-
Notifications
You must be signed in to change notification settings - Fork 140
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Avoid infinite recursion in RuntimeMetricsWriter.FirstChanceException #5704
Conversation
Datadog ReportBranch report: ✅ 0 Failed, 339169 Passed, 1639 Skipped, 14h 5m 45.31s Total Time |
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 (5704) - mean (74ms) : 65, 83
. : milestone, 74,
master - mean (73ms) : 65, 80
. : milestone, 73,
section CallTarget+Inlining+NGEN
This PR (5704) - mean (1,008ms) : 991, 1025
. : milestone, 1008,
master - mean (1,009ms) : 991, 1028
. : milestone, 1009,
gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5704) - mean (112ms) : 109, 114
. : milestone, 112,
master - mean (110ms) : 106, 114
. : milestone, 110,
section CallTarget+Inlining+NGEN
This PR (5704) - mean (714ms) : 689, 739
. : milestone, 714,
master - mean (719ms) : 694, 744
. : milestone, 719,
gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5704) - mean (94ms) : 90, 97
. : milestone, 94,
master - mean (93ms) : 90, 96
. : milestone, 93,
section CallTarget+Inlining+NGEN
This PR (5704) - mean (671ms) : 647, 695
. : milestone, 671,
master - mean (674ms) : 649, 699
. : milestone, 674,
gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5704) - mean (193ms) : 189, 197
. : milestone, 193,
master - mean (195ms) : 191, 200
. : milestone, 195,
section CallTarget+Inlining+NGEN
This PR (5704) - mean (1,104ms) : 1086, 1123
. : milestone, 1104,
master - mean (1,119ms) : 1091, 1146
. : milestone, 1119,
gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5704) - mean (278ms) : 273, 282
. : milestone, 278,
master - mean (279ms) : 274, 283
. : milestone, 279,
section CallTarget+Inlining+NGEN
This PR (5704) - mean (900ms) : 874, 926
. : milestone, 900,
master - mean (912ms) : 882, 942
. : milestone, 912,
gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5704) - mean (266ms) : 262, 270
. : milestone, 266,
master - mean (268ms) : 263, 274
. : milestone, 268,
section CallTarget+Inlining+NGEN
This PR (5704) - mean (881ms) : 856, 906
. : milestone, 881,
master - mean (893ms) : 868, 918
. : milestone, 893,
|
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 (5704) (11.383M) : 0, 11383225
master (11.371M) : 0, 11371297
benchmarks/2.9.0 (11.449M) : 0, 11448607
section Automatic
This PR (5704) (7.636M) : 0, 7635854
master (7.685M) : 0, 7684512
benchmarks/2.9.0 (8.083M) : 0, 8082807
section Trace stats
master (8.028M) : 0, 8027615
section Manual
This PR (5704) (9.874M) : 0, 9873685
master (9.841M) : 0, 9841385
section Manual + Automatic
This PR (5704) (7.189M) : 0, 7188926
master (7.307M) : 0, 7307329
section Version Conflict
master (6.598M) : 0, 6597689
gantt
title Throughput Linux arm64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (5704) (9.598M) : 0, 9597926
master (9.606M) : 0, 9605792
benchmarks/2.9.0 (9.581M) : 0, 9580805
section Automatic
This PR (5704) (6.646M) : 0, 6645622
master (6.493M) : 0, 6493277
section Trace stats
master (6.625M) : 0, 6625006
section Manual
This PR (5704) (8.223M) : 0, 8222507
master (8.310M) : 0, 8310281
section Manual + Automatic
This PR (5704) (6.236M) : 0, 6235780
master (6.216M) : 0, 6216016
section Version Conflict
master (5.693M) : 0, 5693071
gantt
title Throughput Windows x64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (5704) (10.108M) : 0, 10108429
master (10.012M) : 0, 10012096
benchmarks/2.9.0 (10.102M) : 0, 10101741
section Automatic
This PR (5704) (7.360M) : 0, 7359933
master (7.064M) : 0, 7064305
benchmarks/2.9.0 (7.401M) : 0, 7400836
section Trace stats
master (7.473M) : 0, 7473013
section Manual
This PR (5704) (8.909M) : 0, 8909471
master (8.922M) : 0, 8921728
section Manual + Automatic
This PR (5704) (6.989M) : 0, 6989225
master (6.761M) : 0, 6760763
section Version Conflict
master (6.159M) : 0, 6159265
|
Benchmarks Report for tracer 🐌Benchmarks for #5704 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.82 KB | 41.55 KB | -272 B | -0.65% |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | WriteAndFlushEnrichedTraces |
net6.0 | 566μs | 832ns | 3.22μs | 0.553 | 0 | 0 | 41.82 KB |
master | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 652μs | 1.84μs | 7.14μs | 0.327 | 0 | 0 | 41.7 KB |
master | WriteAndFlushEnrichedTraces |
net472 | 851μs | 4.09μs | 15.8μs | 8.45 | 2.53 | 0.422 | 53.23 KB |
#5704 | WriteAndFlushEnrichedTraces |
net6.0 | 558μs | 1.1μs | 4.28μs | 0.551 | 0 | 0 | 41.55 KB |
#5704 | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 660μs | 2.46μs | 9.52μs | 0.327 | 0 | 0 | 41.65 KB |
#5704 | WriteAndFlushEnrichedTraces |
net472 | 847μs | 4.31μs | 20.2μs | 8.08 | 2.55 | 0.425 | 53.26 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.15μs | 0.267ns | 0.962ns | 0.0115 | 0 | 0 | 808 B |
master | ExecuteNonQuery |
netcoreapp3.1 | 1.57μs | 0.762ns | 2.95ns | 0.011 | 0 | 0 | 808 B |
master | ExecuteNonQuery |
net472 | 1.8μs | 1.1ns | 4.1ns | 0.122 | 0 | 0 | 770 B |
#5704 | ExecuteNonQuery |
net6.0 | 1.25μs | 0.636ns | 2.46ns | 0.0112 | 0 | 0 | 808 B |
#5704 | ExecuteNonQuery |
netcoreapp3.1 | 1.59μs | 1.01ns | 3.91ns | 0.0103 | 0 | 0 | 808 B |
#5704 | ExecuteNonQuery |
net472 | 1.73μs | 2.5ns | 9.67ns | 0.122 | 0 | 0 | 770 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.16μs | 0.498ns | 1.86ns | 0.0134 | 0 | 0 | 976 B |
master | CallElasticsearch |
netcoreapp3.1 | 1.5μs | 1.45ns | 5.61ns | 0.0128 | 0 | 0 | 976 B |
master | CallElasticsearch |
net472 | 2.56μs | 2.08ns | 8.04ns | 0.158 | 0.00128 | 0 | 995 B |
master | CallElasticsearchAsync |
net6.0 | 1.33μs | 0.915ns | 3.42ns | 0.0133 | 0 | 0 | 952 B |
master | CallElasticsearchAsync |
netcoreapp3.1 | 1.62μs | 0.879ns | 3.29ns | 0.0138 | 0 | 0 | 1.02 KB |
master | CallElasticsearchAsync |
net472 | 2.67μs | 2.03ns | 7.33ns | 0.166 | 0.00133 | 0 | 1.05 KB |
#5704 | CallElasticsearch |
net6.0 | 1.27μs | 1.49ns | 5.77ns | 0.0134 | 0 | 0 | 976 B |
#5704 | CallElasticsearch |
netcoreapp3.1 | 1.51μs | 1.84ns | 6.62ns | 0.0136 | 0 | 0 | 976 B |
#5704 | CallElasticsearch |
net472 | 2.43μs | 2.96ns | 11.1ns | 0.158 | 0.00122 | 0 | 995 B |
#5704 | CallElasticsearchAsync |
net6.0 | 1.35μs | 0.786ns | 2.94ns | 0.0128 | 0 | 0 | 952 B |
#5704 | CallElasticsearchAsync |
netcoreapp3.1 | 1.63μs | 1.26ns | 4.86ns | 0.0139 | 0 | 0 | 1.02 KB |
#5704 | CallElasticsearchAsync |
net472 | 2.56μs | 1.97ns | 7.37ns | 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.15μs | 0.279ns | 1.04ns | 0.0133 | 0 | 0 | 952 B |
master | ExecuteAsync |
netcoreapp3.1 | 1.63μs | 0.803ns | 3.11ns | 0.0128 | 0 | 0 | 952 B |
master | ExecuteAsync |
net472 | 1.78μs | 0.785ns | 3.04ns | 0.145 | 0 | 0 | 915 B |
#5704 | ExecuteAsync |
net6.0 | 1.23μs | 0.564ns | 2.19ns | 0.0135 | 0 | 0 | 952 B |
#5704 | ExecuteAsync |
netcoreapp3.1 | 1.67μs | 0.982ns | 3.8ns | 0.0125 | 0 | 0 | 952 B |
#5704 | ExecuteAsync |
net472 | 1.75μs | 0.782ns | 2.93ns | 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.34μs | 1.28ns | 4.62ns | 0.0302 | 0 | 0 | 2.22 KB |
master | SendAsync |
netcoreapp3.1 | 5.12μs | 2.44ns | 9.46ns | 0.0358 | 0 | 0 | 2.76 KB |
master | SendAsync |
net472 | 7.68μs | 2.15ns | 8.31ns | 0.499 | 0 | 0 | 3.15 KB |
#5704 | SendAsync |
net6.0 | 4.09μs | 1.52ns | 5.69ns | 0.0308 | 0 | 0 | 2.22 KB |
#5704 | SendAsync |
netcoreapp3.1 | 5.05μs | 2.95ns | 11.4ns | 0.0353 | 0 | 0 | 2.76 KB |
#5704 | SendAsync |
net472 | 7.66μs | 1.78ns | 6.9ns | 0.497 | 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.47μs | 0.339ns | 1.22ns | 0.023 | 0 | 0 | 1.64 KB |
master | EnrichedLog |
netcoreapp3.1 | 2.35μs | 6.76ns | 25.3ns | 0.0215 | 0 | 0 | 1.64 KB |
master | EnrichedLog |
net472 | 2.44μs | 1.79ns | 6.95ns | 0.249 | 0 | 0 | 1.57 KB |
#5704 | EnrichedLog |
net6.0 | 1.47μs | 2.62ns | 9.81ns | 0.0234 | 0 | 0 | 1.64 KB |
#5704 | EnrichedLog |
netcoreapp3.1 | 2.24μs | 1ns | 3.88ns | 0.0224 | 0 | 0 | 1.64 KB |
#5704 | EnrichedLog |
net472 | 2.61μs | 1.37ns | 5.29ns | 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 | 114μs | 239ns | 926ns | 0 | 0 | 0 | 4.28 KB |
master | EnrichedLog |
netcoreapp3.1 | 118μs | 191ns | 739ns | 0.0592 | 0 | 0 | 4.28 KB |
master | EnrichedLog |
net472 | 147μs | 161ns | 601ns | 0.658 | 0.219 | 0 | 4.46 KB |
#5704 | EnrichedLog |
net6.0 | 115μs | 64.9ns | 243ns | 0.0581 | 0 | 0 | 4.28 KB |
#5704 | EnrichedLog |
netcoreapp3.1 | 118μs | 84.8ns | 317ns | 0 | 0 | 0 | 4.28 KB |
#5704 | EnrichedLog |
net472 | 146μs | 122ns | 455ns | 0.655 | 0.218 | 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μs | 1.19ns | 4.46ns | 0.0301 | 0 | 0 | 2.2 KB |
master | EnrichedLog |
netcoreapp3.1 | 4.03μs | 1.6ns | 6.19ns | 0.0302 | 0 | 0 | 2.2 KB |
master | EnrichedLog |
net472 | 4.85μs | 2.97ns | 11.1ns | 0.319 | 0 | 0 | 2.02 KB |
#5704 | EnrichedLog |
net6.0 | 2.94μs | 1.3ns | 4.86ns | 0.0307 | 0 | 0 | 2.2 KB |
#5704 | EnrichedLog |
netcoreapp3.1 | 4.24μs | 1.74ns | 6.52ns | 0.0295 | 0 | 0 | 2.2 KB |
#5704 | EnrichedLog |
net472 | 4.88μs | 2.1ns | 8.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.39μs | 0.75ns | 2.9ns | 0.016 | 0 | 0 | 1.14 KB |
master | SendReceive |
netcoreapp3.1 | 1.71μs | 0.966ns | 3.74ns | 0.0153 | 0 | 0 | 1.14 KB |
master | SendReceive |
net472 | 2.14μs | 1.06ns | 4.12ns | 0.183 | 0.00107 | 0 | 1.16 KB |
#5704 | SendReceive |
net6.0 | 1.32μs | 0.712ns | 2.76ns | 0.0157 | 0 | 0 | 1.14 KB |
#5704 | SendReceive |
netcoreapp3.1 | 1.74μs | 0.626ns | 2.34ns | 0.0156 | 0 | 0 | 1.14 KB |
#5704 | SendReceive |
net472 | 1.93μs | 0.768ns | 2.66ns | 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.75μs | 1.17ns | 4.39ns | 0.022 | 0 | 0 | 1.6 KB |
master | EnrichedLog |
netcoreapp3.1 | 3.9μs | 4.69ns | 18.2ns | 0.0213 | 0 | 0 | 1.65 KB |
master | EnrichedLog |
net472 | 4.36μs | 2.3ns | 8.59ns | 0.324 | 0 | 0 | 2.04 KB |
#5704 | EnrichedLog |
net6.0 | 2.86μs | 0.861ns | 3.33ns | 0.0214 | 0 | 0 | 1.6 KB |
#5704 | EnrichedLog |
netcoreapp3.1 | 4.01μs | 1.71ns | 6.63ns | 0.022 | 0 | 0 | 1.65 KB |
#5704 | EnrichedLog |
net472 | 4.48μs | 2.01ns | 6.97ns | 0.324 | 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 | 398ns | 0.397ns | 1.54ns | 0.00817 | 0 | 0 | 576 B |
master | StartFinishSpan |
netcoreapp3.1 | 580ns | 0.362ns | 1.4ns | 0.00758 | 0 | 0 | 576 B |
master | StartFinishSpan |
net472 | 710ns | 0.743ns | 2.88ns | 0.0916 | 0 | 0 | 578 B |
master | StartFinishScope |
net6.0 | 479ns | 0.244ns | 0.879ns | 0.00967 | 0 | 0 | 696 B |
master | StartFinishScope |
netcoreapp3.1 | 650ns | 0.262ns | 0.979ns | 0.00949 | 0 | 0 | 696 B |
master | StartFinishScope |
net472 | 848ns | 0.538ns | 2.08ns | 0.105 | 0 | 0 | 658 B |
#5704 | StartFinishSpan |
net6.0 | 418ns | 0.244ns | 0.945ns | 0.00816 | 0 | 0 | 576 B |
#5704 | StartFinishSpan |
netcoreapp3.1 | 624ns | 0.639ns | 2.48ns | 0.0078 | 0 | 0 | 576 B |
#5704 | StartFinishSpan |
net472 | 687ns | 0.811ns | 3.03ns | 0.0918 | 0 | 0 | 578 B |
#5704 | StartFinishScope |
net6.0 | 484ns | 0.0966ns | 0.361ns | 0.00971 | 0 | 0 | 696 B |
#5704 | StartFinishScope |
netcoreapp3.1 | 689ns | 1.37ns | 5.32ns | 0.00965 | 0 | 0 | 696 B |
#5704 | StartFinishScope |
net472 | 894ns | 0.317ns | 1.19ns | 0.104 | 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 | 764ns | 0.284ns | 1.1ns | 0.00962 | 0 | 0 | 696 B |
master | RunOnMethodBegin |
netcoreapp3.1 | 949ns | 0.463ns | 1.79ns | 0.00949 | 0 | 0 | 696 B |
master | RunOnMethodBegin |
net472 | 1.12μs | 0.699ns | 2.71ns | 0.105 | 0 | 0 | 658 B |
#5704 | RunOnMethodBegin |
net6.0 | 692ns | 0.225ns | 0.871ns | 0.00973 | 0 | 0 | 696 B |
#5704 | RunOnMethodBegin |
netcoreapp3.1 | 933ns | 0.371ns | 1.44ns | 0.00924 | 0 | 0 | 696 B |
#5704 | RunOnMethodBegin |
net472 | 1.04μs | 0.521ns | 2.02ns | 0.104 | 0 | 0 | 658 B |
Summary of changes
Avoid reentrant calls of RuntimeMetricsWriter.FirstChanceException.
Reason for change
We've seen in crash reports that
exception.GetType().Name
can occasionally throw. When that happens, the new exception causes theFirstChanceException
handler to be called again, and we end up with infinite recursion.Implementation details
Using a thread-static field to track the beginning and end of the
FirstChanceException
event handler. If the flag is already set at the beginning of the method, we bail out.Test coverage
Unfortunately I don't know how to test this, we would need to somehow create a situation where
Exception.GetType().Name
will throw.