Ensure we don't throw a null reference exception in Manual instrumentation#6169
Conversation
…one wrong with the manual instrumentation
Datadog ReportBranch report: ✅ 0 Failed, 364166 Passed, 2095 Skipped, 15h 34m 40.86s Total Time New Flaky Tests (1)
|
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:
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 (6169) - mean (71ms) : 67, 74
. : milestone, 71,
master - mean (70ms) : 68, 72
. : milestone, 70,
section CallTarget+Inlining+NGEN
This PR (6169) - mean (1,112ms) : 1088, 1137
. : milestone, 1112,
master - mean (1,111ms) : 1094, 1128
. : milestone, 1111,
gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6169) - mean (109ms) : 107, 112
. : milestone, 109,
master - mean (109ms) : 106, 112
. : milestone, 109,
section CallTarget+Inlining+NGEN
This PR (6169) - mean (773ms) : 758, 788
. : milestone, 773,
master - mean (768ms) : 751, 784
. : milestone, 768,
gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6169) - mean (93ms) : 89, 97
. : milestone, 93,
master - mean (93ms) : 89, 96
. : milestone, 93,
section CallTarget+Inlining+NGEN
This PR (6169) - mean (725ms) : 710, 739
. : milestone, 725,
master - mean (730ms) : 711, 750
. : milestone, 730,
gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6169) - mean (190ms) : 187, 193
. : milestone, 190,
master - mean (191ms) : 186, 195
. : milestone, 191,
section CallTarget+Inlining+NGEN
This PR (6169) - mean (1,200ms) : 1180, 1219
. : milestone, 1200,
master - mean (1,204ms) : 1176, 1232
. : milestone, 1204,
gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6169) - mean (276ms) : 272, 280
. : milestone, 276,
master - mean (275ms) : 271, 280
. : milestone, 275,
section CallTarget+Inlining+NGEN
This PR (6169) - mean (945ms) : 928, 963
. : milestone, 945,
master - mean (950ms) : 935, 966
. : milestone, 950,
gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6169) - mean (265ms) : 259, 270
. : milestone, 265,
master - mean (265ms) : 261, 268
. : milestone, 265,
section CallTarget+Inlining+NGEN
This PR (6169) - mean (925ms) : 900, 950
. : milestone, 925,
master - mean (928ms) : 906, 950
. : milestone, 928,
|
Benchmarks Report for tracer 🐌Benchmarks for #6169 compared to master:
The following thresholds were used for comparing the benchmark speeds:
Allocation changes below 0.5% are ignored. Benchmark detailsBenchmarks.Trace.ActivityBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Fewer allocations 🎉
|
| Benchmark | Base Allocated | Diff Allocated | Change | Change % |
|---|---|---|---|---|
| Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0 | 41.7 KB | 41.47 KB | -228 B | -0.55% |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | WriteAndFlushEnrichedTraces |
net6.0 | 598μs | 3.4μs | 23.6μs | 0.563 | 0 | 0 | 41.7 KB |
| master | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 767μs | 4.24μs | 26.2μs | 0.383 | 0 | 0 | 41.49 KB |
| master | WriteAndFlushEnrichedTraces |
net472 | 875μs | 2.76μs | 10.3μs | 8.33 | 2.31 | 0.463 | 53.34 KB |
| #6169 | WriteAndFlushEnrichedTraces |
net6.0 | 593μs | 2.74μs | 14.2μs | 0.613 | 0 | 0 | 41.47 KB |
| #6169 | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 703μs | 4.05μs | 33.1μs | 0.351 | 0 | 0 | 41.65 KB |
| #6169 | WriteAndFlushEnrichedTraces |
net472 | 857μs | 3.46μs | 13.4μs | 8.25 | 2.6 | 0.434 | 53.28 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.36μs | 0.76ns | 2.84ns | 0.0143 | 0 | 0 | 1.02 KB |
| master | ExecuteNonQuery |
netcoreapp3.1 | 1.79μs | 1.54ns | 5.76ns | 0.0135 | 0 | 0 | 1.02 KB |
| master | ExecuteNonQuery |
net472 | 2.12μs | 1.71ns | 6.61ns | 0.157 | 0 | 0 | 987 B |
| #6169 | ExecuteNonQuery |
net6.0 | 1.24μs | 1.01ns | 3.64ns | 0.0143 | 0 | 0 | 1.02 KB |
| #6169 | ExecuteNonQuery |
netcoreapp3.1 | 1.8μs | 1.42ns | 5.49ns | 0.0134 | 0 | 0 | 1.02 KB |
| #6169 | ExecuteNonQuery |
net472 | 2.15μs | 3.07ns | 11.9ns | 0.156 | 0 | 0 | 987 B |
Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | CallElasticsearch |
net6.0 | 1.19μs | 2.91ns | 11.3ns | 0.0135 | 0 | 0 | 976 B |
| master | CallElasticsearch |
netcoreapp3.1 | 1.59μs | 0.604ns | 2.26ns | 0.0128 | 0 | 0 | 976 B |
| master | CallElasticsearch |
net472 | 2.59μs | 1.14ns | 4.4ns | 0.157 | 0 | 0 | 995 B |
| master | CallElasticsearchAsync |
net6.0 | 1.3μs | 0.557ns | 2.16ns | 0.0136 | 0 | 0 | 952 B |
| master | CallElasticsearchAsync |
netcoreapp3.1 | 1.66μs | 0.745ns | 2.79ns | 0.0141 | 0 | 0 | 1.02 KB |
| master | CallElasticsearchAsync |
net472 | 2.47μs | 1.53ns | 5.94ns | 0.167 | 0 | 0 | 1.05 KB |
| #6169 | CallElasticsearch |
net6.0 | 1.23μs | 0.569ns | 2.13ns | 0.0136 | 0 | 0 | 976 B |
| #6169 | CallElasticsearch |
netcoreapp3.1 | 1.55μs | 3.6ns | 13.5ns | 0.0133 | 0 | 0 | 976 B |
| #6169 | CallElasticsearch |
net472 | 2.39μs | 1.91ns | 7.14ns | 0.158 | 0 | 0 | 995 B |
| #6169 | CallElasticsearchAsync |
net6.0 | 1.38μs | 0.423ns | 1.58ns | 0.0131 | 0 | 0 | 952 B |
| #6169 | CallElasticsearchAsync |
netcoreapp3.1 | 1.65μs | 0.755ns | 2.72ns | 0.014 | 0 | 0 | 1.02 KB |
| #6169 | CallElasticsearchAsync |
net472 | 2.72μs | 3.06ns | 11.8ns | 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.38μs | 1.03ns | 3.99ns | 0.0131 | 0 | 0 | 952 B |
| master | ExecuteAsync |
netcoreapp3.1 | 1.67μs | 1.8ns | 6.74ns | 0.0123 | 0 | 0 | 952 B |
| master | ExecuteAsync |
net472 | 1.78μs | 0.713ns | 2.76ns | 0.145 | 0 | 0 | 915 B |
| #6169 | ExecuteAsync |
net6.0 | 1.4μs | 1.18ns | 4.4ns | 0.0133 | 0 | 0 | 952 B |
| #6169 | ExecuteAsync |
netcoreapp3.1 | 1.71μs | 3.25ns | 12.6ns | 0.0126 | 0 | 0 | 952 B |
| #6169 | ExecuteAsync |
net472 | 1.83μs | 0.425ns | 1.65ns | 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.18μs | 2.36ns | 9.13ns | 0.031 | 0 | 0 | 2.22 KB |
| master | SendAsync |
netcoreapp3.1 | 5.01μs | 1.48ns | 5.54ns | 0.0378 | 0 | 0 | 2.76 KB |
| master | SendAsync |
net472 | 7.91μs | 1.26ns | 4.72ns | 0.498 | 0 | 0 | 3.15 KB |
| #6169 | SendAsync |
net6.0 | 4.15μs | 4ns | 15.5ns | 0.0312 | 0 | 0 | 2.22 KB |
| #6169 | SendAsync |
netcoreapp3.1 | 5.07μs | 2.13ns | 8.23ns | 0.0356 | 0 | 0 | 2.76 KB |
| #6169 | SendAsync |
net472 | 7.86μs | 2.06ns | 7.99ns | 0.5 | 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.51μs | 0.841ns | 3.03ns | 0.0228 | 0 | 0 | 1.64 KB |
| master | EnrichedLog |
netcoreapp3.1 | 2.2μs | 1.81ns | 6.75ns | 0.0222 | 0 | 0 | 1.64 KB |
| master | EnrichedLog |
net472 | 2.68μs | 1.03ns | 3.98ns | 0.249 | 0 | 0 | 1.57 KB |
| #6169 | EnrichedLog |
net6.0 | 1.47μs | 1.92ns | 7.43ns | 0.0233 | 0 | 0 | 1.64 KB |
| #6169 | EnrichedLog |
netcoreapp3.1 | 2.18μs | 1.08ns | 4.18ns | 0.0229 | 0 | 0 | 1.64 KB |
| #6169 | EnrichedLog |
net472 | 2.6μs | 1.15ns | 4.45ns | 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 | 117μs | 221ns | 856ns | 0 | 0 | 0 | 4.28 KB |
| master | EnrichedLog |
netcoreapp3.1 | 121μs | 273ns | 1.02μs | 0.0597 | 0 | 0 | 4.28 KB |
| master | EnrichedLog |
net472 | 150μs | 188ns | 704ns | 0.673 | 0.224 | 0 | 4.46 KB |
| #6169 | EnrichedLog |
net6.0 | 117μs | 194ns | 752ns | 0.0586 | 0 | 0 | 4.28 KB |
| #6169 | EnrichedLog |
netcoreapp3.1 | 120μs | 248ns | 961ns | 0 | 0 | 0 | 4.28 KB |
| #6169 | EnrichedLog |
net472 | 152μs | 187ns | 723ns | 0.68 | 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.08μs | 1.03ns | 3.98ns | 0.0313 | 0 | 0 | 2.2 KB |
| master | EnrichedLog |
netcoreapp3.1 | 4.23μs | 1.69ns | 6.56ns | 0.0297 | 0 | 0 | 2.2 KB |
| master | EnrichedLog |
net472 | 4.7μs | 1.57ns | 6.09ns | 0.32 | 0 | 0 | 2.02 KB |
| #6169 | EnrichedLog |
net6.0 | 3.14μs | 1.06ns | 4.11ns | 0.0299 | 0 | 0 | 2.2 KB |
| #6169 | EnrichedLog |
netcoreapp3.1 | 4.25μs | 3.12ns | 12.1ns | 0.0298 | 0 | 0 | 2.2 KB |
| #6169 | EnrichedLog |
net472 | 4.93μs | 1.24ns | 4.81ns | 0.319 | 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.4μs | 0.902ns | 3.49ns | 0.0161 | 0 | 0 | 1.14 KB |
| master | SendReceive |
netcoreapp3.1 | 1.77μs | 2.36ns | 9.13ns | 0.015 | 0 | 0 | 1.14 KB |
| master | SendReceive |
net472 | 2.15μs | 0.688ns | 2.48ns | 0.184 | 0.00107 | 0 | 1.16 KB |
| #6169 | SendReceive |
net6.0 | 1.3μs | 1.83ns | 7.09ns | 0.0161 | 0 | 0 | 1.14 KB |
| #6169 | SendReceive |
netcoreapp3.1 | 1.8μs | 1.23ns | 4.75ns | 0.0152 | 0 | 0 | 1.14 KB |
| #6169 | SendReceive |
net472 | 2.09μs | 1.08ns | 4.17ns | 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.55μs | 0.732ns | 2.83ns | 0.0226 | 0 | 0 | 1.6 KB |
| master | EnrichedLog |
netcoreapp3.1 | 3.94μs | 1.57ns | 5.87ns | 0.022 | 0 | 0 | 1.65 KB |
| master | EnrichedLog |
net472 | 4.36μs | 1.31ns | 4.89ns | 0.322 | 0 | 0 | 2.04 KB |
| #6169 | EnrichedLog |
net6.0 | 2.61μs | 1.16ns | 4.48ns | 0.0223 | 0 | 0 | 1.6 KB |
| #6169 | EnrichedLog |
netcoreapp3.1 | 3.89μs | 2.13ns | 8.27ns | 0.0214 | 0 | 0 | 1.65 KB |
| #6169 | EnrichedLog |
net472 | 4.32μs | 3.31ns | 12.8ns | 0.324 | 0 | 0 | 2.04 KB |
Benchmarks.Trace.SpanBenchmark - Slower ⚠️ Same allocations ✔️
Slower ⚠️ in #6169
Benchmark
diff/base
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0
1.139
486.31
554.08
| Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
|---|---|---|---|---|
| Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0 | 1.139 | 486.31 | 554.08 |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | StartFinishSpan |
net6.0 | 400ns | 0.414ns | 1.6ns | 0.00801 | 0 | 0 | 576 B |
| master | StartFinishSpan |
netcoreapp3.1 | 586ns | 0.379ns | 1.47ns | 0.00756 | 0 | 0 | 576 B |
| master | StartFinishSpan |
net472 | 720ns | 0.739ns | 2.86ns | 0.0917 | 0 | 0 | 578 B |
| master | StartFinishScope |
net6.0 | 486ns | 0.378ns | 1.46ns | 0.00984 | 0 | 0 | 696 B |
| master | StartFinishScope |
netcoreapp3.1 | 762ns | 4.05ns | 19.8ns | 0.00946 | 0 | 0 | 696 B |
| master | StartFinishScope |
net472 | 859ns | 0.956ns | 3.7ns | 0.104 | 0 | 0 | 658 B |
| #6169 | StartFinishSpan |
net6.0 | 415ns | 0.385ns | 1.49ns | 0.00806 | 0 | 0 | 576 B |
| #6169 | StartFinishSpan |
netcoreapp3.1 | 552ns | 0.422ns | 1.64ns | 0.00803 | 0 | 0 | 576 B |
| #6169 | StartFinishSpan |
net472 | 701ns | 0.681ns | 2.64ns | 0.0916 | 0 | 0 | 578 B |
| #6169 | StartFinishScope |
net6.0 | 554ns | 0.389ns | 1.51ns | 0.00972 | 0 | 0 | 696 B |
| #6169 | StartFinishScope |
netcoreapp3.1 | 777ns | 0.492ns | 1.7ns | 0.00927 | 0 | 0 | 696 B |
| #6169 | StartFinishScope |
net472 | 871ns | 0.459ns | 1.78ns | 0.105 | 0 | 0 | 658 B |
Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | RunOnMethodBegin |
net6.0 | 659ns | 1.67ns | 6.47ns | 0.00979 | 0 | 0 | 696 B |
| master | RunOnMethodBegin |
netcoreapp3.1 | 942ns | 1.28ns | 4.44ns | 0.00906 | 0 | 0 | 696 B |
| master | RunOnMethodBegin |
net472 | 1.08μs | 0.95ns | 3.68ns | 0.104 | 0 | 0 | 658 B |
| #6169 | RunOnMethodBegin |
net6.0 | 664ns | 0.282ns | 1.09ns | 0.00961 | 0 | 0 | 696 B |
| #6169 | RunOnMethodBegin |
netcoreapp3.1 | 885ns | 0.778ns | 3.01ns | 0.0093 | 0 | 0 | 696 B |
| #6169 | RunOnMethodBegin |
net472 | 1.17μs | 1.31ns | 5.08ns | 0.104 | 0 | 0 | 658 B |
Throughput/Crank Report ⚡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 (6169) (11.201M) : 0, 11200981
master (11.119M) : 0, 11118546
benchmarks/2.9.0 (11.081M) : 0, 11080577
section Automatic
This PR (6169) (7.418M) : 0, 7418412
master (7.321M) : 0, 7321152
benchmarks/2.9.0 (7.732M) : 0, 7732233
section Trace stats
master (7.757M) : 0, 7756918
section Manual
master (11.210M) : 0, 11209846
section Manual + Automatic
This PR (6169) (6.900M) : 0, 6900462
master (6.740M) : 0, 6740459
section DD_TRACE_ENABLED=0
master (10.109M) : 0, 10109349
gantt
title Throughput Linux arm64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6169) (9.603M) : 0, 9602769
master (9.561M) : 0, 9560673
benchmarks/2.9.0 (9.798M) : 0, 9798067
section Automatic
This PR (6169) (6.519M) : 0, 6518648
master (6.578M) : 0, 6578194
section Trace stats
master (6.868M) : 0, 6867545
section Manual
master (9.568M) : 0, 9568124
section Manual + Automatic
This PR (6169) (6.137M) : 0, 6136794
master (6.203M) : 0, 6203435
section DD_TRACE_ENABLED=0
master (8.858M) : 0, 8857806
gantt
title Throughput Windows x64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6169) (9.908M) : 0, 9908189
master (9.889M) : 0, 9889232
benchmarks/2.9.0 (10.067M) : 0, 10067315
section Automatic
This PR (6169) (6.379M) : 0, 6378626
master (6.396M) : 0, 6396160
benchmarks/2.9.0 (7.552M) : 0, 7552193
section Trace stats
master (7.205M) : 0, 7205159
section Manual
master (9.853M) : 0, 9852595
section Manual + Automatic
This PR (6169) (5.854M) : 0, 5854240
master (5.939M) : 0, 5939480
section DD_TRACE_ENABLED=0
master (9.222M) : 0, 9221606
|
Summary of changes
Check
instance.AutomaticTracerfornullbefore using it instead of castingReason for change
In #6124, we were seeing null reference exceptions. This was indicative of a separate (major) issue related to r2r (see #6168), but we still shouldn't have been throwing null refs in this case.
Implementation details
(Datadog.Trace.Tracer)instance.AutomaticTracernullStartActiveImplementationIntegrationif we can't match, so that we still have visibility that something went wrong on the managed side.Test coverage
Tested locally to confirm it fixes the error in the tests introduced in #6168, but as those fix the root cause anyway, we won't be able to easily test for this invalid scenario
Other details
Relates to #6124