-
Notifications
You must be signed in to change notification settings - Fork 145
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
Fix Isolated Azure Functions performance when using ASP.NET Core
Integration
#6567
base: master
Are you sure you want to change the base?
Conversation
Not really sure why, but it was off in its own little world at the bottom of the solution file. In a seemingly different /tracer/test/test-applications/azure-functions/ directory.
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 (6567) - mean (69ms) : 66, 72
. : milestone, 69,
master - mean (69ms) : 65, 73
. : milestone, 69,
section CallTarget+Inlining+NGEN
This PR (6567) - mean (982ms) : 947, 1016
. : milestone, 982,
master - mean (979ms) : 952, 1006
. : milestone, 979,
gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6567) - mean (107ms) : 105, 109
. : milestone, 107,
master - mean (107ms) : 104, 110
. : milestone, 107,
section CallTarget+Inlining+NGEN
This PR (6567) - mean (678ms) : 664, 693
. : milestone, 678,
master - mean (678ms) : 663, 693
. : milestone, 678,
gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6567) - mean (91ms) : 89, 93
. : milestone, 91,
master - mean (91ms) : 89, 93
. : milestone, 91,
section CallTarget+Inlining+NGEN
This PR (6567) - mean (628ms) : 609, 647
. : milestone, 628,
master - mean (633ms) : 616, 650
. : milestone, 633,
gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6567) - mean (190ms) : 186, 194
. : milestone, 190,
master - mean (189ms) : 185, 193
. : milestone, 189,
section CallTarget+Inlining+NGEN
This PR (6567) - mean (1,090ms) : 1068, 1113
. : milestone, 1090,
master - mean (1,091ms) : 1058, 1124
. : milestone, 1091,
gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6567) - mean (276ms) : 272, 280
. : milestone, 276,
master - mean (275ms) : 270, 279
. : milestone, 275,
section CallTarget+Inlining+NGEN
This PR (6567) - mean (867ms) : 832, 902
. : milestone, 867,
master - mean (868ms) : 838, 898
. : milestone, 868,
gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6567) - mean (265ms) : 259, 270
. : milestone, 265,
master - mean (264ms) : 259, 270
. : milestone, 264,
section CallTarget+Inlining+NGEN
This PR (6567) - mean (846ms) : 804, 887
. : milestone, 846,
master - mean (846ms) : 817, 874
. : milestone, 846,
|
Datadog ReportBranch report: ✅ 0 Failed, 548343 Passed, 3785 Skipped, 32h 44m 39.71s Total Time |
Benchmarks Report for tracer 🐌Benchmarks for #6567 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 - Faster 🎉 Same allocations ✔️
|
Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.AspNetCoreBenchmark.SendRequest‑net6.0 | 1.232 | 156,129.28 | 126,769.60 | bimodal |
Benchmarks.Trace.AspNetCoreBenchmark.SendRequest‑netcoreapp3.1 | 1.203 | 170,862.24 | 142,034.46 |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | SendRequest |
net6.0 | 158μs | 1.12μs | 11μs | 0.155 | 0 | 0 | 14.47 KB |
master | SendRequest |
netcoreapp3.1 | 173μs | 1.11μs | 11.1μs | 0.162 | 0 | 0 | 17.27 KB |
master | SendRequest |
net472 | 0.000217ns | 0.000191ns | 0.000715ns | 0 | 0 | 0 | 0 b |
#6567 | SendRequest |
net6.0 | 127μs | 492ns | 1.9μs | 0.19 | 0 | 0 | 14.47 KB |
#6567 | SendRequest |
netcoreapp3.1 | 143μs | 563ns | 2.18μs | 0.213 | 0 | 0 | 17.27 KB |
#6567 | SendRequest |
net472 | 0.00316ns | 0.00138ns | 0.00517ns | 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 | 591μs | 3.25μs | 18.9μs | 0.553 | 0 | 0 | 41.62 KB |
master | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 662μs | 3.59μs | 21.6μs | 0.345 | 0 | 0 | 41.72 KB |
master | WriteAndFlushEnrichedTraces |
net472 | 842μs | 2.5μs | 9.35μs | 8.28 | 2.48 | 0.414 | 53.28 KB |
#6567 | WriteAndFlushEnrichedTraces |
net6.0 | 586μs | 3.22μs | 18.8μs | 0.563 | 0 | 0 | 41.7 KB |
#6567 | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 701μs | 4.04μs | 30.8μs | 0.331 | 0 | 0 | 41.83 KB |
#6567 | WriteAndFlushEnrichedTraces |
net472 | 861μs | 3.89μs | 15.1μs | 8.39 | 2.52 | 0.419 | 53.33 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.39μs | 1.71ns | 6.63ns | 0.014 | 0 | 0 | 1.02 KB |
master | ExecuteNonQuery |
netcoreapp3.1 | 1.75μs | 2.08ns | 8.06ns | 0.0138 | 0 | 0 | 1.02 KB |
master | ExecuteNonQuery |
net472 | 2.07μs | 2.12ns | 8.19ns | 0.156 | 0.00104 | 0 | 987 B |
#6567 | ExecuteNonQuery |
net6.0 | 1.41μs | 0.851ns | 3.29ns | 0.0142 | 0 | 0 | 1.02 KB |
#6567 | ExecuteNonQuery |
netcoreapp3.1 | 1.79μs | 1.52ns | 5.69ns | 0.0135 | 0 | 0 | 1.02 KB |
#6567 | ExecuteNonQuery |
net472 | 2.11μs | 2.26ns | 8.74ns | 0.156 | 0.00106 | 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.24μs | 1.02ns | 3.82ns | 0.0137 | 0 | 0 | 976 B |
master | CallElasticsearch |
netcoreapp3.1 | 1.61μs | 0.766ns | 2.76ns | 0.0129 | 0 | 0 | 976 B |
master | CallElasticsearch |
net472 | 2.61μs | 2.51ns | 9.71ns | 0.158 | 0 | 0 | 995 B |
master | CallElasticsearchAsync |
net6.0 | 1.3μs | 0.695ns | 2.69ns | 0.013 | 0 | 0 | 952 B |
master | CallElasticsearchAsync |
netcoreapp3.1 | 1.65μs | 0.636ns | 2.38ns | 0.014 | 0 | 0 | 1.02 KB |
master | CallElasticsearchAsync |
net472 | 2.65μs | 1.54ns | 5.98ns | 0.167 | 0 | 0 | 1.05 KB |
#6567 | CallElasticsearch |
net6.0 | 1.16μs | 0.762ns | 2.85ns | 0.014 | 0 | 0 | 976 B |
#6567 | CallElasticsearch |
netcoreapp3.1 | 1.58μs | 1.17ns | 4.23ns | 0.0134 | 0 | 0 | 976 B |
#6567 | CallElasticsearch |
net472 | 2.52μs | 1.08ns | 3.9ns | 0.157 | 0 | 0 | 995 B |
#6567 | CallElasticsearchAsync |
net6.0 | 1.41μs | 0.89ns | 3.45ns | 0.0135 | 0 | 0 | 952 B |
#6567 | CallElasticsearchAsync |
netcoreapp3.1 | 1.62μs | 0.925ns | 3.58ns | 0.0138 | 0 | 0 | 1.02 KB |
#6567 | CallElasticsearchAsync |
net472 | 2.73μs | 1.88ns | 7.28ns | 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.27μs | 0.793ns | 3.07ns | 0.0134 | 0 | 0 | 952 B |
master | ExecuteAsync |
netcoreapp3.1 | 1.7μs | 0.985ns | 3.68ns | 0.0128 | 0 | 0 | 952 B |
master | ExecuteAsync |
net472 | 1.85μs | 0.318ns | 1.19ns | 0.145 | 0 | 0 | 915 B |
#6567 | ExecuteAsync |
net6.0 | 1.28μs | 0.555ns | 2.08ns | 0.0135 | 0 | 0 | 952 B |
#6567 | ExecuteAsync |
netcoreapp3.1 | 1.67μs | 1.89ns | 7.32ns | 0.0125 | 0 | 0 | 952 B |
#6567 | ExecuteAsync |
net472 | 1.8μs | 0.56ns | 2.17ns | 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.3μs | 1.31ns | 5.09ns | 0.0323 | 0 | 0 | 2.31 KB |
master | SendAsync |
netcoreapp3.1 | 5.33μs | 1.51ns | 5.64ns | 0.037 | 0 | 0 | 2.85 KB |
master | SendAsync |
net472 | 7.3μs | 1.5ns | 5.62ns | 0.496 | 0 | 0 | 3.12 KB |
#6567 | SendAsync |
net6.0 | 4.39μs | 3.4ns | 12.7ns | 0.0329 | 0 | 0 | 2.31 KB |
#6567 | SendAsync |
netcoreapp3.1 | 5.3μs | 2.39ns | 8.6ns | 0.0371 | 0 | 0 | 2.85 KB |
#6567 | SendAsync |
net472 | 7.55μs | 1.78ns | 6.88ns | 0.495 | 0 | 0 | 3.12 KB |
Benchmarks.Trace.ILoggerBenchmark - Slower ⚠️ Same allocations ✔️
Slower ⚠️ in #6567
Benchmark
diff/base
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.ILoggerBenchmark.EnrichedLog‑net6.0
1.120
1,460.35
1,635.35
Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.ILoggerBenchmark.EnrichedLog‑net6.0 | 1.120 | 1,460.35 | 1,635.35 |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | EnrichedLog |
net6.0 | 1.46μs | 0.76ns | 2.74ns | 0.0233 | 0 | 0 | 1.64 KB |
master | EnrichedLog |
netcoreapp3.1 | 2.25μs | 0.883ns | 3.3ns | 0.0217 | 0 | 0 | 1.64 KB |
master | EnrichedLog |
net472 | 2.67μs | 0.7ns | 2.52ns | 0.249 | 0 | 0 | 1.57 KB |
#6567 | EnrichedLog |
net6.0 | 1.64μs | 0.817ns | 2.95ns | 0.0229 | 0 | 0 | 1.64 KB |
#6567 | EnrichedLog |
netcoreapp3.1 | 2.27μs | 5.41ns | 20.9ns | 0.0226 | 0 | 0 | 1.64 KB |
#6567 | EnrichedLog |
net472 | 2.72μs | 1.45ns | 5.63ns | 0.25 | 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 | 105ns | 393ns | 0.0579 | 0 | 0 | 4.28 KB |
master | EnrichedLog |
netcoreapp3.1 | 120μs | 101ns | 390ns | 0.0597 | 0 | 0 | 4.28 KB |
master | EnrichedLog |
net472 | 151μs | 128ns | 478ns | 0.68 | 0.227 | 0 | 4.46 KB |
#6567 | EnrichedLog |
net6.0 | 118μs | 152ns | 589ns | 0 | 0 | 0 | 4.28 KB |
#6567 | EnrichedLog |
netcoreapp3.1 | 120μs | 186ns | 719ns | 0.0602 | 0 | 0 | 4.28 KB |
#6567 | EnrichedLog |
net472 | 151μs | 159ns | 615ns | 0.677 | 0.226 | 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 | 0.714ns | 2.77ns | 0.0316 | 0 | 0 | 2.2 KB |
master | EnrichedLog |
netcoreapp3.1 | 4.19μs | 1.04ns | 4.02ns | 0.0293 | 0 | 0 | 2.2 KB |
master | EnrichedLog |
net472 | 4.83μs | 0.89ns | 3.45ns | 0.319 | 0 | 0 | 2.02 KB |
#6567 | EnrichedLog |
net6.0 | 3.08μs | 2.18ns | 8.43ns | 0.0308 | 0 | 0 | 2.2 KB |
#6567 | EnrichedLog |
netcoreapp3.1 | 4.17μs | 1.08ns | 4.2ns | 0.0293 | 0 | 0 | 2.2 KB |
#6567 | EnrichedLog |
net472 | 4.86μs | 1.05ns | 3.94ns | 0.321 | 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.41μs | 0.793ns | 2.97ns | 0.0162 | 0 | 0 | 1.14 KB |
master | SendReceive |
netcoreapp3.1 | 1.82μs | 2.63ns | 10.2ns | 0.0146 | 0 | 0 | 1.14 KB |
master | SendReceive |
net472 | 2.05μs | 1.43ns | 5.33ns | 0.183 | 0 | 0 | 1.16 KB |
#6567 | SendReceive |
net6.0 | 1.38μs | 0.715ns | 2.77ns | 0.0158 | 0 | 0 | 1.14 KB |
#6567 | SendReceive |
netcoreapp3.1 | 1.78μs | 0.985ns | 3.69ns | 0.0151 | 0 | 0 | 1.14 KB |
#6567 | SendReceive |
net472 | 2.1μs | 0.871ns | 3.37ns | 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.67μs | 0.824ns | 2.85ns | 0.0227 | 0 | 0 | 1.6 KB |
master | EnrichedLog |
netcoreapp3.1 | 3.96μs | 2.02ns | 7.84ns | 0.0217 | 0 | 0 | 1.65 KB |
master | EnrichedLog |
net472 | 4.31μs | 4.75ns | 18.4ns | 0.322 | 0 | 0 | 2.04 KB |
#6567 | EnrichedLog |
net6.0 | 2.75μs | 0.841ns | 3.26ns | 0.022 | 0 | 0 | 1.6 KB |
#6567 | EnrichedLog |
netcoreapp3.1 | 3.85μs | 0.768ns | 2.97ns | 0.0212 | 0 | 0 | 1.65 KB |
#6567 | EnrichedLog |
net472 | 4.5μs | 3.47ns | 13.5ns | 0.322 | 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 | 394ns | 0.266ns | 1.03ns | 0.00815 | 0 | 0 | 576 B |
master | StartFinishSpan |
netcoreapp3.1 | 576ns | 0.311ns | 1.17ns | 0.00759 | 0 | 0 | 576 B |
master | StartFinishSpan |
net472 | 653ns | 0.271ns | 1.05ns | 0.0917 | 0 | 0 | 578 B |
master | StartFinishScope |
net6.0 | 489ns | 0.242ns | 0.938ns | 0.00982 | 0 | 0 | 696 B |
master | StartFinishScope |
netcoreapp3.1 | 679ns | 0.382ns | 1.48ns | 0.00947 | 0 | 0 | 696 B |
master | StartFinishScope |
net472 | 899ns | 0.644ns | 2.49ns | 0.104 | 0 | 0 | 658 B |
#6567 | StartFinishSpan |
net6.0 | 420ns | 0.191ns | 0.741ns | 0.00798 | 0 | 0 | 576 B |
#6567 | StartFinishSpan |
netcoreapp3.1 | 626ns | 0.476ns | 1.72ns | 0.00781 | 0 | 0 | 576 B |
#6567 | StartFinishSpan |
net472 | 716ns | 0.673ns | 2.61ns | 0.0918 | 0 | 0 | 578 B |
#6567 | StartFinishScope |
net6.0 | 481ns | 0.386ns | 1.5ns | 0.00966 | 0 | 0 | 696 B |
#6567 | StartFinishScope |
netcoreapp3.1 | 752ns | 0.881ns | 3.41ns | 0.00936 | 0 | 0 | 696 B |
#6567 | StartFinishScope |
net472 | 956ns | 1.03ns | 3.71ns | 0.104 | 0 | 0 | 658 B |
Benchmarks.Trace.TraceAnnotationsBenchmark - Slower ⚠️ Same allocations ✔️
Slower ⚠️ in #6567
Benchmark
diff/base
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0
1.154
676.03
779.88
Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0 | 1.154 | 676.03 | 779.88 |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | RunOnMethodBegin |
net6.0 | 676ns | 0.284ns | 1.06ns | 0.00967 | 0 | 0 | 696 B |
master | RunOnMethodBegin |
netcoreapp3.1 | 942ns | 0.568ns | 2.2ns | 0.00944 | 0 | 0 | 696 B |
master | RunOnMethodBegin |
net472 | 1.07μs | 0.639ns | 2.48ns | 0.104 | 0 | 0 | 658 B |
#6567 | RunOnMethodBegin |
net6.0 | 780ns | 0.682ns | 2.64ns | 0.00976 | 0 | 0 | 696 B |
#6567 | RunOnMethodBegin |
netcoreapp3.1 | 955ns | 0.568ns | 2.13ns | 0.00914 | 0 | 0 | 696 B |
#6567 | RunOnMethodBegin |
net472 | 1.18μs | 0.775ns | 2.9ns | 0.105 | 0 | 0 | 658 B |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Great work, thanks!
// because of this they cause a lot of flake in the snapshots where they shift places | ||
// opting to just scrub them from the snapshots - we also don't think that the spans provide much | ||
// value so they may be removed from being traced. | ||
var filteredSpans = FilterOutSocketsHttpHandler(spans); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yep, its the orange spans.
I've filtered them out as they would change places with the aspnet_core.request
ones in the snapshots as from what I could tell their timings would be too close so the snapshot ordering would change with one leap frogging the another.
Are we still agreed that there are changes in addition to this one that we think we should make in the future, to simplify the traces? e.g. the aspnetcore span seems low value too, right?
Yeah
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
they would change places with the aspnet_core.request ones in the snapshots
Seems like a bug in the span ordering in that case 🤔 they should be sorted consistently, as they have different resource names 🤔 But anyway, happy to punt on it for now 👍
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Hmm my understanding is that it only checks the root span resource name right?
public static SettingsTask VerifySpans(
IReadOnlyCollection<MockSpan> spans,
VerifySettings settings,
Func<IReadOnlyCollection<MockSpan>, IOrderedEnumerable<MockSpan>>? orderSpans = null)
{
// Ensure a static ordering for the spans
var orderedSpans = orderSpans?.Invoke(spans) ??
spans
.OrderBy(x => GetRootSpanResourceName(x, spans))
.ThenBy(x => GetSpanDepth(x, spans))
.ThenBy(x => x.Start)
.ThenBy(x => x.Duration);
return Verifier.Verify(orderedSpans, settings);
}
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
ooooh, you're right, that's an oversight 👍
Though it also highlights the parenting issue in general as there shouldn't be peers 😉🙈 But like we said - for another day
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
// this uses the ASP.NET Core integration | ||
// this will cause the one function app (func.exe) to proxy | ||
// the HTTP trigger functions HTTP request to the ASP NET Core app | ||
// instead of sending it (primarily) as a gRPC message |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
These comments are gold :chefkiss: 🙏
Summary of changes
This fixes an application performance issue when using Isolated Azure Functions with the
ASP.NET Core
Integration caused by us modifying astatic
TypedData
object when requests were being proxied via HTTP.https://learn.microsoft.com/en-us/azure/azure-functions/dotnet-isolated-process-guide?tabs=hostbuilder%2Cwindows#aspnet-core-integration
Reason for change
When using the
ASP.NET Core
integration with an Isolated Azure Functions application (ConfigureFunctionsWebApplication
) under load the workerASP.NET Core
application would start to timeout on requests or hang waiting for responses from the function application.Ultimately it appears that within
GrpcMessageConversionExtensions
astatic
instance of theTypedData
that we used for injection was added specifically when the requests were being proxied via HTTP requests. Under load we'd end up modifying this shared object with our propagated headers which would ultimately cause requests to start timing out as we shouldn't have been modifying those headers.Implementation details
We now check for when the requests are being proxied and if so we generate a new, non-
static
TypedData
instance that we can safely inject headers into.Additionally, injection into these will now correctly adhere to whether or not the Functions automatic instrumentation is enabled or not.
I was able to reliably reproduce the issue prior to the fix and haven't seen the issue post-fix.
Test coverage
Samples.AzureFunctions.V4Isolated.AspNetCore.SdkV1
testsASP.NET Core
integration with V1 of the NuGetsSamples.AzureFunctions.V4Isolated.AspNetCore.Sdk
testsASP.NET Core
integration with V2 of the NuGetsASP.NET Core
andgRPC
Function models.Other details
Fixes #6494
Noted some potential improvements in the signal-to-noise ratio of the traces / spans produced by the Functions integration that we'll bring up as future improvements.