-
Notifications
You must be signed in to change notification settings - Fork 150
Avoid creating new tasks on wait #7777
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
base: master
Are you sure you want to change the base?
Conversation
Execution-Time Benchmarks Report ⏱️Execution-time results for samples comparing This PR (7777) and master. ✅ No regressions detected - check the details below Full Metrics ComparisonFakeDbCommand
HttpMessageHandler
Comparison explanationExecution-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 highlighted 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). Duration chartsFakeDbCommand (.NET Framework 4.8)gantt
title Execution time (ms) FakeDbCommand (.NET Framework 4.8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (7777) - mean (75ms) : 70, 79
master - mean (77ms) : 72, 82
section Bailout
This PR (7777) - mean (79ms) : 74, 84
master - mean (80ms) : 76, 84
section CallTarget+Inlining+NGEN
This PR (7777) - mean (1,111ms) : 1035, 1188
master - mean (1,131ms) : 1058, 1205
FakeDbCommand (.NET Core 3.1)gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (7777) - mean (116ms) : 107, 124
master - mean (120ms) : 114, 126
section Bailout
This PR (7777) - mean (120ms) : 115, 126
master - mean (120ms) : 115, 126
section CallTarget+Inlining+NGEN
This PR (7777) - mean (791ms) : 758, 824
master - mean (819ms) : 765, 873
FakeDbCommand (.NET 6)gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (7777) - mean (102ms) : 95, 110
master - mean (105ms) : 98, 112
section Bailout
This PR (7777) - mean (105ms) : 97, 112
master - mean (108ms) : 100, 115
section CallTarget+Inlining+NGEN
This PR (7777) - mean (743ms) : 712, 774
master - mean (767ms) : 724, 810
FakeDbCommand (.NET 8)gantt
title Execution time (ms) FakeDbCommand (.NET 8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (7777) - mean (103ms) : 96, 110
master - mean (104ms) : 98, 110
section Bailout
This PR (7777) - mean (102ms) : 96, 108
master - mean (104ms) : 97, 111
section CallTarget+Inlining+NGEN
This PR (7777) - mean (699ms) : 673, 726
master - mean (717ms) : 686, 747
HttpMessageHandler (.NET Framework 4.8)gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (7777) - mean (193ms) : 189, 197
master - mean (194ms) : 189, 199
section Bailout
This PR (7777) - mean (196ms) : 193, 199
master - mean (197ms) : 194, 200
section CallTarget+Inlining+NGEN
This PR (7777) - mean (1,173ms) : 1108, 1237
master - mean (1,175ms) : 1116, 1234
HttpMessageHandler (.NET Core 3.1)gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (7777) - mean (277ms) : 272, 281
master - mean (277ms) : 271, 284
section Bailout
This PR (7777) - mean (278ms) : 273, 282
master - mean (278ms) : 274, 282
section CallTarget+Inlining+NGEN
This PR (7777) - mean (946ms) : 903, 989
master - mean (964ms) : 914, 1014
HttpMessageHandler (.NET 6)gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (7777) - mean (270ms) : 266, 274
master - mean (271ms) : 266, 276
section Bailout
This PR (7777) - mean (269ms) : 266, 272
master - mean (270ms) : 266, 274
section CallTarget+Inlining+NGEN
This PR (7777) - mean (923ms) : 873, 973
master - mean (934ms) : 880, 988
HttpMessageHandler (.NET 8)gantt
title Execution time (ms) HttpMessageHandler (.NET 8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (7777) - mean (268ms) : 265, 272
master - mean (269ms) : 263, 275
section Bailout
This PR (7777) - mean (269ms) : 265, 272
master - mean (269ms) : 266, 272
section CallTarget+Inlining+NGEN
This PR (7777) - mean (851ms) : 836, 866
master - mean (860ms) : 843, 878
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
BenchmarksBenchmarks Report for benchmark platform 🐌Benchmarks for #7777 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 ✔️ More allocations
|
| Benchmark | Base Allocated | Diff Allocated | Change | Change % |
|---|---|---|---|---|
| Benchmarks.Trace.ActivityBenchmark.StartStopWithChild‑net472 | 5.99 KB | 6.06 KB | 69 B | 1.15% |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | StartStopWithChild |
net6.0 | 10.4μs | 58.1ns | 394ns | 0 | 0 | 0 | 5.51 KB |
| master | StartStopWithChild |
netcoreapp3.1 | 13.6μs | 67.3ns | 293ns | 0 | 0 | 0 | 5.73 KB |
| master | StartStopWithChild |
net472 | 21.7μs | 116ns | 612ns | 1.01 | 0.405 | 0.101 | 5.99 KB |
| #7777 | StartStopWithChild |
net6.0 | 10.9μs | 59.3ns | 346ns | 0 | 0 | 0 | 5.52 KB |
| #7777 | StartStopWithChild |
netcoreapp3.1 | 13.8μs | 67.8ns | 303ns | 0 | 0 | 0 | 5.73 KB |
| #7777 | StartStopWithChild |
net472 | 21.9μs | 122ns | 789ns | 0.954 | 0.239 | 0 | 6.06 KB |
Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Fewer allocations 🎉
Fewer allocations 🎉 in #7777
Benchmark
Base Allocated
Diff Allocated
Change
Change %
Benchmarks.Trace.AgentWriterBenchmark.WriteAndFlushEnrichedTraces‑net472
3.35 KB
3.31 KB
-46 B
-1.37%
| Benchmark | Base Allocated | Diff Allocated | Change | Change % |
|---|---|---|---|---|
| Benchmarks.Trace.AgentWriterBenchmark.WriteAndFlushEnrichedTraces‑net472 | 3.35 KB | 3.31 KB | -46 B | -1.37% |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | WriteAndFlushEnrichedTraces |
net6.0 | 949μs | 244ns | 947ns | 0 | 0 | 0 | 2.71 KB |
| master | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 1.03ms | 205ns | 795ns | 0 | 0 | 0 | 2.7 KB |
| master | WriteAndFlushEnrichedTraces |
net472 | 1.22ms | 1.26μs | 4.89μs | 0 | 0 | 0 | 3.35 KB |
| #7777 | WriteAndFlushEnrichedTraces |
net6.0 | 936μs | 112ns | 418ns | 0 | 0 | 0 | 2.71 KB |
| #7777 | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 1.03ms | 96ns | 332ns | 0 | 0 | 0 | 2.7 KB |
| #7777 | WriteAndFlushEnrichedTraces |
net472 | 1.21ms | 53.9ns | 202ns | 0 | 0 | 0 | 3.31 KB |
Benchmarks.Trace.Asm.AppSecBodyBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | AllCycleSimpleBody |
net6.0 | 1.07μs | 6.16ns | 39.4ns | 0 | 0 | 0 | 1.22 KB |
| master | AllCycleSimpleBody |
netcoreapp3.1 | 1.44μs | 7.63ns | 37.4ns | 0 | 0 | 0 | 1.2 KB |
| master | AllCycleSimpleBody |
net472 | 1.02μs | 0.441ns | 1.65ns | 0.193 | 0 | 0 | 1.23 KB |
| master | AllCycleMoreComplexBody |
net6.0 | 7.12μs | 33.7ns | 135ns | 0 | 0 | 0 | 4.72 KB |
| master | AllCycleMoreComplexBody |
netcoreapp3.1 | 9.24μs | 10.5ns | 40.8ns | 0 | 0 | 0 | 4.62 KB |
| master | AllCycleMoreComplexBody |
net472 | 7.56μs | 5.55ns | 21.5ns | 0.718 | 0 | 0 | 4.74 KB |
| master | ObjectExtractorSimpleBody |
net6.0 | 313ns | 1.68ns | 9.52ns | 0 | 0 | 0 | 280 B |
| master | ObjectExtractorSimpleBody |
netcoreapp3.1 | 403ns | 1.94ns | 8.23ns | 0 | 0 | 0 | 272 B |
| master | ObjectExtractorSimpleBody |
net472 | 295ns | 0.0319ns | 0.12ns | 0.0432 | 0 | 0 | 281 B |
| master | ObjectExtractorMoreComplexBody |
net6.0 | 6.39μs | 28.9ns | 108ns | 0 | 0 | 0 | 3.78 KB |
| master | ObjectExtractorMoreComplexBody |
netcoreapp3.1 | 7.78μs | 35.9ns | 139ns | 0 | 0 | 0 | 3.69 KB |
| master | ObjectExtractorMoreComplexBody |
net472 | 6.7μs | 3.35ns | 12.5ns | 0.6 | 0 | 0 | 3.8 KB |
| #7777 | AllCycleSimpleBody |
net6.0 | 1.09μs | 5.85ns | 33.6ns | 0 | 0 | 0 | 1.22 KB |
| #7777 | AllCycleSimpleBody |
netcoreapp3.1 | 1.4μs | 7.63ns | 43.2ns | 0 | 0 | 0 | 1.2 KB |
| #7777 | AllCycleSimpleBody |
net472 | 1.02μs | 0.789ns | 2.95ns | 0.19 | 0 | 0 | 1.23 KB |
| #7777 | AllCycleMoreComplexBody |
net6.0 | 7.28μs | 36.7ns | 164ns | 0 | 0 | 0 | 4.72 KB |
| #7777 | AllCycleMoreComplexBody |
netcoreapp3.1 | 9.08μs | 6.36ns | 24.6ns | 0 | 0 | 0 | 4.62 KB |
| #7777 | AllCycleMoreComplexBody |
net472 | 7.62μs | 3.12ns | 12.1ns | 0.723 | 0 | 0 | 4.74 KB |
| #7777 | ObjectExtractorSimpleBody |
net6.0 | 312ns | 1.54ns | 6.34ns | 0 | 0 | 0 | 280 B |
| #7777 | ObjectExtractorSimpleBody |
netcoreapp3.1 | 403ns | 2.23ns | 12.6ns | 0 | 0 | 0 | 272 B |
| #7777 | ObjectExtractorSimpleBody |
net472 | 303ns | 0.0945ns | 0.366ns | 0.0441 | 0 | 0 | 281 B |
| #7777 | ObjectExtractorMoreComplexBody |
net6.0 | 6.28μs | 33ns | 158ns | 0 | 0 | 0 | 3.78 KB |
| #7777 | ObjectExtractorMoreComplexBody |
netcoreapp3.1 | 7.96μs | 39.1ns | 156ns | 0 | 0 | 0 | 3.69 KB |
| #7777 | ObjectExtractorMoreComplexBody |
net472 | 6.8μs | 5.37ns | 20.8ns | 0.573 | 0 | 0 | 3.8 KB |
Benchmarks.Trace.Asm.AppSecEncoderBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | EncodeArgs |
net6.0 | 77.6μs | 108ns | 418ns | 0 | 0 | 0 | 32.4 KB |
| master | EncodeArgs |
netcoreapp3.1 | 97.2μs | 335ns | 1.3μs | 0 | 0 | 0 | 32.4 KB |
| master | EncodeArgs |
net472 | 110μs | 39.9ns | 144ns | 4.99 | 0 | 0 | 32.51 KB |
| master | EncodeLegacyArgs |
net6.0 | 145μs | 20.3ns | 78.5ns | 0 | 0 | 0 | 2.15 KB |
| master | EncodeLegacyArgs |
netcoreapp3.1 | 199μs | 281ns | 1.09μs | 0 | 0 | 0 | 2.14 KB |
| master | EncodeLegacyArgs |
net472 | 262μs | 65.8ns | 255ns | 0 | 0 | 0 | 2.16 KB |
| #7777 | EncodeArgs |
net6.0 | 77.6μs | 158ns | 610ns | 0 | 0 | 0 | 32.4 KB |
| #7777 | EncodeArgs |
netcoreapp3.1 | 97μs | 269ns | 1.04μs | 0 | 0 | 0 | 32.4 KB |
| #7777 | EncodeArgs |
net472 | 109μs | 30.9ns | 115ns | 4.94 | 0 | 0 | 32.5 KB |
| #7777 | EncodeLegacyArgs |
net6.0 | 147μs | 40.4ns | 156ns | 0 | 0 | 0 | 2.15 KB |
| #7777 | EncodeLegacyArgs |
netcoreapp3.1 | 197μs | 124ns | 463ns | 0 | 0 | 0 | 2.14 KB |
| #7777 | EncodeLegacyArgs |
net472 | 265μs | 131ns | 506ns | 0 | 0 | 0 | 2.16 KB |
Benchmarks.Trace.Asm.AppSecWafBenchmark - Slower ⚠️ Same allocations ✔️
Slower ⚠️ in #7777
Benchmark
diff/base
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.Asm.AppSecWafBenchmark.RunWafRealisticBenchmarkWithAttack‑netcoreapp3.1
2.424
295,648.32
716,578.05
Benchmarks.Trace.Asm.AppSecWafBenchmark.RunWafRealisticBenchmark‑netcoreapp3.1
2.092
409,719.46
856,937.08
| Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
|---|---|---|---|---|
| Benchmarks.Trace.Asm.AppSecWafBenchmark.RunWafRealisticBenchmarkWithAttack‑netcoreapp3.1 | 2.424 | 295,648.32 | 716,578.05 | |
| Benchmarks.Trace.Asm.AppSecWafBenchmark.RunWafRealisticBenchmark‑netcoreapp3.1 | 2.092 | 409,719.46 | 856,937.08 |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | RunWafRealisticBenchmark |
net6.0 | 401μs | 24.7ns | 92.4ns | 0 | 0 | 0 | 4.56 KB |
| master | RunWafRealisticBenchmark |
netcoreapp3.1 | 410μs | 61.6ns | 230ns | 0 | 0 | 0 | 4.48 KB |
| master | RunWafRealisticBenchmark |
net472 | 429μs | 66.2ns | 256ns | 0 | 0 | 0 | 4.66 KB |
| master | RunWafRealisticBenchmarkWithAttack |
net6.0 | 284μs | 38.6ns | 144ns | 0 | 0 | 0 | 2.24 KB |
| master | RunWafRealisticBenchmarkWithAttack |
netcoreapp3.1 | 296μs | 157ns | 610ns | 0 | 0 | 0 | 2.22 KB |
| master | RunWafRealisticBenchmarkWithAttack |
net472 | 315μs | 19.3ns | 69.4ns | 0 | 0 | 0 | 2.29 KB |
| #7777 | RunWafRealisticBenchmark |
net6.0 | 392μs | 126ns | 489ns | 0 | 0 | 0 | 4.55 KB |
| #7777 | RunWafRealisticBenchmark |
netcoreapp3.1 | 797μs | 11.8μs | 117μs | 0 | 0 | 0 | 4.48 KB |
| #7777 | RunWafRealisticBenchmark |
net472 | 429μs | 55ns | 213ns | 0 | 0 | 0 | 4.66 KB |
| #7777 | RunWafRealisticBenchmarkWithAttack |
net6.0 | 286μs | 95.5ns | 357ns | 0 | 0 | 0 | 2.24 KB |
| #7777 | RunWafRealisticBenchmarkWithAttack |
netcoreapp3.1 | 677μs | 12.1μs | 121μs | 0 | 0 | 0 | 2.22 KB |
| #7777 | RunWafRealisticBenchmarkWithAttack |
net472 | 309μs | 24.2ns | 93.9ns | 0 | 0 | 0 | 2.29 KB |
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | SendRequest |
net6.0 | 61.2μs | 283ns | 1.36μs | 0 | 0 | 0 | 14.52 KB |
| master | SendRequest |
netcoreapp3.1 | 72.9μs | 214ns | 801ns | 0 | 0 | 0 | 17.42 KB |
| master | SendRequest |
net472 | 0.00499ns | 0.0018ns | 0.00698ns | 0 | 0 | 0 | 0 b |
| #7777 | SendRequest |
net6.0 | 61.7μs | 39.9ns | 149ns | 0 | 0 | 0 | 14.52 KB |
| #7777 | SendRequest |
netcoreapp3.1 | 71μs | 255ns | 986ns | 0 | 0 | 0 | 17.42 KB |
| #7777 | SendRequest |
net472 | 0.00412ns | 0.00156ns | 0.00605ns | 0 | 0 | 0 | 0 b |
Benchmarks.Trace.CharSliceBenchmark - Same speed ✔️ More allocations ⚠️
More allocations ⚠️ in #7777
Benchmark
Base Allocated
Diff Allocated
Change
Change %
Benchmarks.Trace.CharSliceBenchmark.OptimizedCharSlice‑net472
0 b
73 B
73 B
∞
Benchmarks.Trace.CharSliceBenchmark.OptimizedCharSliceWithPool‑net472
0 b
47 B
47 B
∞
Benchmarks.Trace.CharSliceBenchmark.OptimizedCharSliceWithPool‑net6.0
3 B
5 B
2 B
66.67%
| Benchmark | Base Allocated | Diff Allocated | Change | Change % |
|---|---|---|---|---|
| Benchmarks.Trace.CharSliceBenchmark.OptimizedCharSlice‑net472 | 0 b | 73 B | 73 B | ∞ |
| Benchmarks.Trace.CharSliceBenchmark.OptimizedCharSliceWithPool‑net472 | 0 b | 47 B | 47 B | ∞ |
| Benchmarks.Trace.CharSliceBenchmark.OptimizedCharSliceWithPool‑net6.0 | 3 B | 5 B | 2 B | 66.67% |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | OriginalCharSlice |
net6.0 | 1.91ms | 1.31μs | 5.06μs | 0 | 0 | 0 | 640.01 KB |
| master | OriginalCharSlice |
netcoreapp3.1 | 2.12ms | 5.72μs | 22.2μs | 0 | 0 | 0 | 640 KB |
| master | OriginalCharSlice |
net472 | 2.56ms | 918ns | 3.44μs | 100 | 0 | 0 | 641.95 KB |
| master | OptimizedCharSlice |
net6.0 | 1.45ms | 526ns | 2.04μs | 0 | 0 | 0 | 4 B |
| master | OptimizedCharSlice |
netcoreapp3.1 | 1.77ms | 718ns | 2.78μs | 0 | 0 | 0 | 1 B |
| master | OptimizedCharSlice |
net472 | 2ms | 315ns | 1.22μs | 0 | 0 | 0 | 0 b |
| master | OptimizedCharSliceWithPool |
net6.0 | 831μs | 22.4ns | 83.8ns | 0 | 0 | 0 | 3 B |
| master | OptimizedCharSliceWithPool |
netcoreapp3.1 | 811μs | 76.3ns | 296ns | 0 | 0 | 0 | 0 b |
| master | OptimizedCharSliceWithPool |
net472 | 1.13ms | 120ns | 466ns | 0 | 0 | 0 | 0 b |
| #7777 | OriginalCharSlice |
net6.0 | 2.01ms | 4.62μs | 17.3μs | 0 | 0 | 0 | 640.01 KB |
| #7777 | OriginalCharSlice |
netcoreapp3.1 | 2.17ms | 7.07μs | 27.4μs | 0 | 0 | 0 | 640 KB |
| #7777 | OriginalCharSlice |
net472 | 2.76ms | 264ns | 986ns | 100 | 0 | 0 | 641.95 KB |
| #7777 | OptimizedCharSlice |
net6.0 | 1.5ms | 88.5ns | 343ns | 0 | 0 | 0 | 4 B |
| #7777 | OptimizedCharSlice |
netcoreapp3.1 | 1.76ms | 325ns | 1.26μs | 0 | 0 | 0 | 1 B |
| #7777 | OptimizedCharSlice |
net472 | 2.09ms | 158ns | 614ns | 0 | 0 | 0 | 73 B |
| #7777 | OptimizedCharSliceWithPool |
net6.0 | 852μs | 29.5ns | 111ns | 0 | 0 | 0 | 5 B |
| #7777 | OptimizedCharSliceWithPool |
netcoreapp3.1 | 892μs | 146ns | 546ns | 0 | 0 | 0 | 0 b |
| #7777 | OptimizedCharSliceWithPool |
net472 | 1.13ms | 102ns | 395ns | 0 | 0 | 0 | 47 B |
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Slower ⚠️ Fewer allocations 🎉
Slower ⚠️ in #7777
Benchmark
diff/base
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net472
1.138
975,198.56
1,109,608.65
Fewer allocations 🎉 in #7777
Benchmark
Base Allocated
Diff Allocated
Change
Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net472
56.15 KB
55.76 KB
-395 B
-0.70%
| Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
|---|---|---|---|---|
| Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net472 | 1.138 | 975,198.56 | 1,109,608.65 |
| Benchmark | Base Allocated | Diff Allocated | Change | Change % |
|---|---|---|---|---|
| Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net472 | 56.15 KB | 55.76 KB | -395 B | -0.70% |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | WriteAndFlushEnrichedTraces |
net6.0 | 735μs | 653ns | 2.53μs | 0 | 0 | 0 | 41.6 KB |
| master | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 730μs | 4.14μs | 28.4μs | 0 | 0 | 0 | 41.94 KB |
| master | WriteAndFlushEnrichedTraces |
net472 | 972μs | 4.41μs | 16.5μs | 4.81 | 0 | 0 | 56.15 KB |
| #7777 | WriteAndFlushEnrichedTraces |
net6.0 | 701μs | 688ns | 2.48μs | 0 | 0 | 0 | 41.67 KB |
| #7777 | WriteAndFlushEnrichedTraces |
netcoreapp3.1 | 730μs | 2.14μs | 8μs | 0 | 0 | 0 | 41.96 KB |
| #7777 | WriteAndFlushEnrichedTraces |
net472 | 1.12ms | 5.78μs | 29.5μs | 4.81 | 0 | 0 | 55.76 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.91μs | 8.69ns | 33.6ns | 0 | 0 | 0 | 1.02 KB |
| master | ExecuteNonQuery |
netcoreapp3.1 | 2.7μs | 8.43ns | 32.6ns | 0 | 0 | 0 | 1.02 KB |
| master | ExecuteNonQuery |
net472 | 2.86μs | 2.66ns | 10.3ns | 0.143 | 0.0143 | 0 | 987 B |
| #7777 | ExecuteNonQuery |
net6.0 | 1.87μs | 8.79ns | 35.1ns | 0 | 0 | 0 | 1.02 KB |
| #7777 | ExecuteNonQuery |
netcoreapp3.1 | 2.52μs | 10.5ns | 40.6ns | 0 | 0 | 0 | 1.02 KB |
| #7777 | ExecuteNonQuery |
net472 | 2.76μs | 3.93ns | 15.2ns | 0.149 | 0.0136 | 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.69μs | 3.01ns | 11.7ns | 0 | 0 | 0 | 1.03 KB |
| master | CallElasticsearch |
netcoreapp3.1 | 2.2μs | 8.38ns | 31.4ns | 0 | 0 | 0 | 1.03 KB |
| master | CallElasticsearch |
net472 | 3.71μs | 2.84ns | 10.3ns | 0.151 | 0 | 0 | 1.04 KB |
| master | CallElasticsearchAsync |
net6.0 | 1.88μs | 9.33ns | 42.8ns | 0 | 0 | 0 | 1.01 KB |
| master | CallElasticsearchAsync |
netcoreapp3.1 | 2.35μs | 11.8ns | 50.2ns | 0 | 0 | 0 | 1.08 KB |
| master | CallElasticsearchAsync |
net472 | 3.83μs | 12.5ns | 48.5ns | 0.17 | 0 | 0 | 1.1 KB |
| #7777 | CallElasticsearch |
net6.0 | 1.69μs | 1.84ns | 7.12ns | 0 | 0 | 0 | 1.03 KB |
| #7777 | CallElasticsearch |
netcoreapp3.1 | 2.22μs | 5.3ns | 19.8ns | 0 | 0 | 0 | 1.03 KB |
| #7777 | CallElasticsearch |
net472 | 3.62μs | 2.41ns | 9.34ns | 0.163 | 0 | 0 | 1.04 KB |
| #7777 | CallElasticsearchAsync |
net6.0 | 1.82μs | 8.36ns | 32.4ns | 0 | 0 | 0 | 1.01 KB |
| #7777 | CallElasticsearchAsync |
netcoreapp3.1 | 2.46μs | 12.4ns | 56.7ns | 0 | 0 | 0 | 1.08 KB |
| #7777 | CallElasticsearchAsync |
net472 | 3.67μs | 2.73ns | 10.6ns | 0.165 | 0 | 0 | 1.1 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.9μs | 7.01ns | 27.2ns | 0 | 0 | 0 | 952 B |
| master | ExecuteAsync |
netcoreapp3.1 | 2.59μs | 2.17ns | 8.39ns | 0 | 0 | 0 | 952 B |
| master | ExecuteAsync |
net472 | 2.6μs | 1.3ns | 5.05ns | 0.142 | 0 | 0 | 915 B |
| #7777 | ExecuteAsync |
net6.0 | 1.91μs | 9.28ns | 39.4ns | 0 | 0 | 0 | 952 B |
| #7777 | ExecuteAsync |
netcoreapp3.1 | 2.47μs | 6.18ns | 21.4ns | 0 | 0 | 0 | 952 B |
| #7777 | ExecuteAsync |
net472 | 2.69μs | 3.69ns | 13.8ns | 0.135 | 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 | 6.92μs | 5.9ns | 22.9ns | 0 | 0 | 0 | 2.36 KB |
| master | SendAsync |
netcoreapp3.1 | 8.85μs | 23.9ns | 92.5ns | 0 | 0 | 0 | 2.9 KB |
| master | SendAsync |
net472 | 12.1μs | 9.8ns | 37.9ns | 0.486 | 0 | 0 | 3.18 KB |
| #7777 | SendAsync |
net6.0 | 6.8μs | 8.06ns | 31.2ns | 0 | 0 | 0 | 2.36 KB |
| #7777 | SendAsync |
netcoreapp3.1 | 8.3μs | 37.4ns | 145ns | 0 | 0 | 0 | 2.9 KB |
| #7777 | SendAsync |
net472 | 12.2μs | 10.9ns | 42.1ns | 0.487 | 0 | 0 | 3.18 KB |
Benchmarks.Trace.Iast.StringAspectsBenchmark - Faster 🎉 More allocations ⚠️
Faster 🎉 in #7777
Benchmark
base/diff
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑net6.0
1.254
465,250.00
371,100.00
More allocations ⚠️ in #7777
Benchmark
Base Allocated
Diff Allocated
Change
Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑net472
278.53 KB
286.72 KB
8.19 KB
2.94%
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑netcoreapp3.1
255.67 KB
260.92 KB
5.25 KB
2.05%
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark‑netcoreapp3.1
42.64 KB
43.42 KB
784 B
1.84%
Fewer allocations 🎉 in #7777
Benchmark
Base Allocated
Diff Allocated
Change
Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark‑net6.0
43.78 KB
43.44 KB
-336 B
-0.77%
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark‑net472
65.54 KB
57.34 KB
-8.19 KB
-12.50%
| Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality |
|---|---|---|---|---|
| Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑net6.0 | 1.254 | 465,250.00 | 371,100.00 |
| Benchmark | Base Allocated | Diff Allocated | Change | Change % |
|---|---|---|---|---|
| Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑net472 | 278.53 KB | 286.72 KB | 8.19 KB | 2.94% |
| Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑netcoreapp3.1 | 255.67 KB | 260.92 KB | 5.25 KB | 2.05% |
| Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark‑netcoreapp3.1 | 42.64 KB | 43.42 KB | 784 B | 1.84% |
| Benchmark | Base Allocated | Diff Allocated | Change | Change % |
|---|---|---|---|---|
| Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark‑net6.0 | 43.78 KB | 43.44 KB | -336 B | -0.77% |
| Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark‑net472 | 65.54 KB | 57.34 KB | -8.19 KB | -12.50% |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | StringConcatBenchmark |
net6.0 | 50.1μs | 909ns | 9.09μs | 0 | 0 | 0 | 43.78 KB |
| master | StringConcatBenchmark |
netcoreapp3.1 | 47.1μs | 237ns | 1.01μs | 0 | 0 | 0 | 42.64 KB |
| master | StringConcatBenchmark |
net472 | 58μs | 264ns | 988ns | 0 | 0 | 0 | 65.54 KB |
| master | StringConcatAspectBenchmark |
net6.0 | 467μs | 1.65μs | 5.7μs | 0 | 0 | 0 | 275.65 KB |
| master | StringConcatAspectBenchmark |
netcoreapp3.1 | 490μs | 2.26μs | 8.47μs | 0 | 0 | 0 | 255.67 KB |
| master | StringConcatAspectBenchmark |
net472 | 409μs | 2.31μs | 16.5μs | 0 | 0 | 0 | 278.53 KB |
| #7777 | StringConcatBenchmark |
net6.0 | 45.8μs | 258ns | 2.46μs | 0 | 0 | 0 | 43.44 KB |
| #7777 | StringConcatBenchmark |
netcoreapp3.1 | 54.2μs | 683ns | 6.76μs | 0 | 0 | 0 | 43.42 KB |
| #7777 | StringConcatBenchmark |
net472 | 57.2μs | 111ns | 401ns | 0 | 0 | 0 | 57.34 KB |
| #7777 | StringConcatAspectBenchmark |
net6.0 | 391μs | 4.11μs | 38.8μs | 0 | 0 | 0 | 275.49 KB |
| #7777 | StringConcatAspectBenchmark |
netcoreapp3.1 | 519μs | 1.7μs | 5.89μs | 0 | 0 | 0 | 260.92 KB |
| #7777 | StringConcatAspectBenchmark |
net472 | 400μs | 2.1μs | 10.7μs | 0 | 0 | 0 | 286.72 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 | 2.67μs | 13.4ns | 59.8ns | 0 | 0 | 0 | 1.7 KB |
| master | EnrichedLog |
netcoreapp3.1 | 3.76μs | 13.5ns | 52.3ns | 0 | 0 | 0 | 1.7 KB |
| master | EnrichedLog |
net472 | 4.02μs | 4.66ns | 18.1ns | 0.243 | 0 | 0 | 1.64 KB |
| #7777 | EnrichedLog |
net6.0 | 2.67μs | 13.4ns | 64.3ns | 0 | 0 | 0 | 1.7 KB |
| #7777 | EnrichedLog |
netcoreapp3.1 | 3.73μs | 10.9ns | 42.2ns | 0 | 0 | 0 | 1.7 KB |
| #7777 | EnrichedLog |
net472 | 4.03μs | 3.81ns | 14.7ns | 0.243 | 0 | 0 | 1.64 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 | 123μs | 95.9ns | 371ns | 0 | 0 | 0 | 4.31 KB |
| master | EnrichedLog |
netcoreapp3.1 | 128μs | 253ns | 911ns | 0 | 0 | 0 | 4.31 KB |
| master | EnrichedLog |
net472 | 169μs | 94.3ns | 353ns | 0 | 0 | 0 | 4.52 KB |
| #7777 | EnrichedLog |
net6.0 | 123μs | 61.2ns | 229ns | 0 | 0 | 0 | 4.31 KB |
| #7777 | EnrichedLog |
netcoreapp3.1 | 129μs | 212ns | 820ns | 0 | 0 | 0 | 4.31 KB |
| #7777 | EnrichedLog |
net472 | 166μs | 27.4ns | 106ns | 0 | 0 | 0 | 4.51 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 | 5.17μs | 18.2ns | 70.7ns | 0 | 0 | 0 | 2.26 KB |
| master | EnrichedLog |
netcoreapp3.1 | 6.68μs | 27.4ns | 106ns | 0 | 0 | 0 | 2.26 KB |
| master | EnrichedLog |
net472 | 7.58μs | 12.9ns | 50ns | 0.301 | 0 | 0 | 2.08 KB |
| #7777 | EnrichedLog |
net6.0 | 5.06μs | 7.87ns | 30.5ns | 0 | 0 | 0 | 2.26 KB |
| #7777 | EnrichedLog |
netcoreapp3.1 | 6.82μs | 15.7ns | 60.7ns | 0 | 0 | 0 | 2.26 KB |
| #7777 | EnrichedLog |
net472 | 7.74μs | 6.74ns | 26.1ns | 0.308 | 0 | 0 | 2.08 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.95μs | 8.97ns | 35.9ns | 0 | 0 | 0 | 1.2 KB |
| master | SendReceive |
netcoreapp3.1 | 2.72μs | 13.4ns | 53.5ns | 0 | 0 | 0 | 1.2 KB |
| master | SendReceive |
net472 | 3.01μs | 3.5ns | 13.6ns | 0.18 | 0 | 0 | 1.2 KB |
| #7777 | SendReceive |
net6.0 | 1.98μs | 9.2ns | 35.6ns | 0 | 0 | 0 | 1.2 KB |
| #7777 | SendReceive |
netcoreapp3.1 | 2.51μs | 12.1ns | 50ns | 0 | 0 | 0 | 1.2 KB |
| #7777 | SendReceive |
net472 | 3.11μs | 1.66ns | 6.42ns | 0.186 | 0 | 0 | 1.2 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 | 4.39μs | 12.4ns | 46.5ns | 0 | 0 | 0 | 1.58 KB |
| master | EnrichedLog |
netcoreapp3.1 | 5.68μs | 7.46ns | 28.9ns | 0 | 0 | 0 | 1.63 KB |
| master | EnrichedLog |
net472 | 6.69μs | 6.1ns | 23.6ns | 0.299 | 0 | 0 | 2.03 KB |
| #7777 | EnrichedLog |
net6.0 | 4.31μs | 8.25ns | 31.9ns | 0 | 0 | 0 | 1.58 KB |
| #7777 | EnrichedLog |
netcoreapp3.1 | 5.6μs | 20.6ns | 79.7ns | 0 | 0 | 0 | 1.63 KB |
| #7777 | EnrichedLog |
net472 | 6.55μs | 6.72ns | 26ns | 0.293 | 0 | 0 | 2.03 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 | 784ns | 0.189ns | 0.706ns | 0 | 0 | 0 | 576 B |
| master | StartFinishSpan |
netcoreapp3.1 | 989ns | 5.1ns | 23.9ns | 0 | 0 | 0 | 576 B |
| master | StartFinishSpan |
net472 | 931ns | 0.474ns | 1.84ns | 0.0888 | 0 | 0 | 578 B |
| master | StartFinishScope |
net6.0 | 922ns | 4.14ns | 15.5ns | 0 | 0 | 0 | 696 B |
| master | StartFinishScope |
netcoreapp3.1 | 1.23μs | 4.75ns | 18.4ns | 0 | 0 | 0 | 696 B |
| master | StartFinishScope |
net472 | 1.12μs | 0.434ns | 1.68ns | 0.102 | 0 | 0 | 658 B |
| #7777 | StartFinishSpan |
net6.0 | 779ns | 0.43ns | 1.61ns | 0 | 0 | 0 | 576 B |
| #7777 | StartFinishSpan |
netcoreapp3.1 | 972ns | 5.28ns | 29.4ns | 0 | 0 | 0 | 576 B |
| #7777 | StartFinishSpan |
net472 | 936ns | 2.59ns | 10ns | 0.091 | 0 | 0 | 578 B |
| #7777 | StartFinishScope |
net6.0 | 922ns | 4.78ns | 17.9ns | 0 | 0 | 0 | 696 B |
| #7777 | StartFinishScope |
netcoreapp3.1 | 1.23μs | 6.16ns | 23.9ns | 0 | 0 | 0 | 696 B |
| #7777 | StartFinishScope |
net472 | 1.12μs | 0.884ns | 3.42ns | 0.101 | 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 | 1.07μs | 5.18ns | 20.7ns | 0 | 0 | 0 | 696 B |
| master | RunOnMethodBegin |
netcoreapp3.1 | 1.46μs | 3.91ns | 15.2ns | 0 | 0 | 0 | 696 B |
| master | RunOnMethodBegin |
net472 | 1.48μs | 1.61ns | 6.23ns | 0.104 | 0 | 0 | 658 B |
| #7777 | RunOnMethodBegin |
net6.0 | 1.07μs | 0.663ns | 2.48ns | 0 | 0 | 0 | 696 B |
| #7777 | RunOnMethodBegin |
netcoreapp3.1 | 1.48μs | 5.8ns | 22.4ns | 0 | 0 | 0 | 696 B |
| #7777 | RunOnMethodBegin |
net472 | 1.45μs | 1.03ns | 4.01ns | 0.102 | 0 | 0 | 658 B |
bouwkast
left a comment
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.
LGTM seems like it should be a lot less allocations now.
Were you able to reproduce this or benchmark at all or is this just an educated guess?
| var tcs = new TaskCompletionSource<bool>(); | ||
| using (new Timer(s => ((TaskCompletionSource<bool>)s!).SetResult(true), tcs, _waitTimeSpan, Timeout.InfiniteTimeSpan)) | ||
| { | ||
| await Task.WhenAny(_processExit.Task, tcs.Task).ConfigureAwait(false); |
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.
We aren't responding / reacting to _processExit.Task anymore but I don't think a big deal
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.
We aren't responding / reacting to _processExit.Task anymore but I don't think a big deal
Yeah, given it's only a 15ms wait, I think that's fine, but it does make me wonder... a 15ms wait period makes this is a pretty fast spinning loop, no? 😕For context, we flush traces every 1000ms (1s)... On low-core (1) machines would this not potentially be taking up a lot of thread/CPU time?
What's more, the _resetEvent.Wait() that's never triggered is effectively a Thread.Sleep(). And doing a Thread.Sleep on a thread pool thread is generally not a good idea, as it blocks anything else doing work. @tonyredondo did a bunch of work to remove all the Thread.Sleep() from our async code for exactly this reason. If we do want to dedicate a thread to this, I think we need to turn this loop into a sync loop and create a dedicated long-running thread, but that might be more work than we'd like.
Overall, I don't know if we have any evidence that the TCS and Tasks here are the source of the perf issue yet? and I wonder if it's the potentially small value of _waitTimeSpan that's causing the issue due to this loop spinning too fast? 🤔 Have we considered alternatives like increasing the buffering wait time? Or taking an approach similar to the agent writer where we have a longer buffering period, with dedicated flushing when the buffers get to a certain "fullness"? It'll be a trade-off obviously, but I'm not sure which is best
| var tcs = new TaskCompletionSource<bool>(); | ||
| using (new Timer(s => ((TaskCompletionSource<bool>)s!).SetResult(true), tcs, _waitTimeSpan, Timeout.InfiniteTimeSpan)) | ||
| { | ||
| await Task.WhenAny(_processExit.Task, tcs.Task).ConfigureAwait(false); |
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.
We aren't responding / reacting to _processExit.Task anymore but I don't think a big deal
Yeah, given it's only a 15ms wait, I think that's fine, but it does make me wonder... a 15ms wait period makes this is a pretty fast spinning loop, no? 😕For context, we flush traces every 1000ms (1s)... On low-core (1) machines would this not potentially be taking up a lot of thread/CPU time?
What's more, the _resetEvent.Wait() that's never triggered is effectively a Thread.Sleep(). And doing a Thread.Sleep on a thread pool thread is generally not a good idea, as it blocks anything else doing work. @tonyredondo did a bunch of work to remove all the Thread.Sleep() from our async code for exactly this reason. If we do want to dedicate a thread to this, I think we need to turn this loop into a sync loop and create a dedicated long-running thread, but that might be more work than we'd like.
Overall, I don't know if we have any evidence that the TCS and Tasks here are the source of the perf issue yet? and I wonder if it's the potentially small value of _waitTimeSpan that's causing the issue due to this loop spinning too fast? 🤔 Have we considered alternatives like increasing the buffering wait time? Or taking an approach similar to the agent writer where we have a longer buffering period, with dedicated flushing when the buffers get to a certain "fullness"? It'll be a trade-off obviously, but I'm not sure which is best
@andrewlock From the
My guess is that it comes from this code. Tasks wait due to thread pool starvation, causing I didn't know that |
To be clear, I haven't looked into what it's actually like, but it's fundamentally not releasing the thread which is what I was getting at 🙂 |
|

Summary of changes
Avoid creating extra tasks/timer. A simple ManualResetEventSlim is used now.
Reason for change
See this ticket.
Implementation details
Based on the information we have it seems like the main reason for extra overhead comes from the "Finalizer" thread which calls
CloseHandletoo frequently. It's not clear what causes the kernel resource allocation/disposal and why it only happens in customer's environment.The change avoids creating extra objects and instead rely on a single
ManualResetEventSlimandWaitcall with a timeout.