Increase the margin for the number of threads in RuntimeMetricsWriterTests#5329
Merged
Conversation
Datadog ReportBranch report: ✅ 0 Failed, 328862 Passed, 1603 Skipped, 35m 31.42s Wall Time |
Member
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 (5329) - mean (72ms) : 65, 78
. : milestone, 72,
master - mean (73ms) : 64, 82
. : milestone, 73,
section CallTarget+Inlining+NGEN
This PR (5329) - mean (1,000ms) : 975, 1026
. : milestone, 1000,
master - mean (1,002ms) : 980, 1024
. : milestone, 1002,
gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5329) - mean (109ms) : 106, 111
. : milestone, 109,
master - mean (110ms) : 106, 114
. : milestone, 110,
section CallTarget+Inlining+NGEN
This PR (5329) - mean (717ms) : 696, 738
. : milestone, 717,
master - mean (718ms) : 697, 738
. : milestone, 718,
gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5329) - mean (93ms) : 91, 96
. : milestone, 93,
master - mean (94ms) : 90, 97
. : milestone, 94,
section CallTarget+Inlining+NGEN
This PR (5329) - mean (678ms) : 646, 710
. : milestone, 678,
master - mean (680ms) : 661, 699
. : milestone, 680,
gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5329) - mean (187ms) : 185, 190
. : milestone, 187,
master - mean (188ms) : 185, 191
. : milestone, 188,
section CallTarget+Inlining+NGEN
This PR (5329) - mean (1,079ms) : 1051, 1107
. : milestone, 1079,
master - mean (1,078ms) : 1060, 1097
. : milestone, 1078,
gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5329) - mean (271ms) : 266, 276
. : milestone, 271,
master - mean (271ms) : 267, 275
. : milestone, 271,
section CallTarget+Inlining+NGEN
This PR (5329) - mean (874ms) : 851, 896
. : milestone, 874,
master - mean (872ms) : 849, 894
. : milestone, 872,
gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5329) - mean (260ms) : 256, 264
. : milestone, 260,
master - mean (261ms) : 257, 265
. : milestone, 261,
section CallTarget+Inlining+NGEN
This PR (5329) - mean (852ms) : 822, 883
. : milestone, 852,
master - mean (856ms) : 830, 882
. : milestone, 856,
|
Member
Benchmarks Report for tracer 🐌Benchmarks for #5329 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 ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.SpanBenchmark - Faster 🎉 Same allocations ✔️
|
| Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality |
|---|---|---|---|---|
| Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net472 | 1.177 | 1,053.19 | 894.68 |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | StartFinishSpan |
net6.0 | 483ns | 0.807ns | 3.02ns | 0.00761 | 0 | 0 | 552 B |
| master | StartFinishSpan |
netcoreapp3.1 | 710ns | 0.615ns | 2.38ns | 0.00752 | 0 | 0 | 552 B |
| master | StartFinishSpan |
net472 | 782ns | 0.396ns | 1.53ns | 0.0878 | 0 | 0 | 554 B |
| master | StartFinishScope |
net6.0 | 620ns | 0.915ns | 3.55ns | 0.00928 | 0 | 0 | 672 B |
| master | StartFinishScope |
netcoreapp3.1 | 840ns | 0.78ns | 3.02ns | 0.00918 | 0 | 0 | 672 B |
| master | StartFinishScope |
net472 | 1.05μs | 1.14ns | 4.28ns | 0.101 | 0 | 0 | 634 B |
| #5329 | StartFinishSpan |
net6.0 | 538ns | 0.695ns | 2.69ns | 0.00768 | 0 | 0 | 552 B |
| #5329 | StartFinishSpan |
netcoreapp3.1 | 712ns | 0.764ns | 2.86ns | 0.00735 | 0 | 0 | 552 B |
| #5329 | StartFinishSpan |
net472 | 778ns | 0.6ns | 2.32ns | 0.0879 | 0 | 0 | 554 B |
| #5329 | StartFinishScope |
net6.0 | 571ns | 0.305ns | 1.18ns | 0.0095 | 0 | 0 | 672 B |
| #5329 | StartFinishScope |
netcoreapp3.1 | 876ns | 0.952ns | 3.69ns | 0.00919 | 0 | 0 | 672 B |
| #5329 | StartFinishScope |
net472 | 895ns | 0.573ns | 2.22ns | 0.1 | 0 | 0 | 634 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 | 683ns | 0.781ns | 3.03ns | 0.00958 | 0 | 0 | 672 B |
| master | RunOnMethodBegin |
netcoreapp3.1 | 955ns | 0.782ns | 3.03ns | 0.00911 | 0 | 0 | 672 B |
| master | RunOnMethodBegin |
net472 | 1.17μs | 1.6ns | 5.76ns | 0.1 | 0 | 0 | 634 B |
| #5329 | RunOnMethodBegin |
net6.0 | 631ns | 0.176ns | 0.681ns | 0.00954 | 0 | 0 | 672 B |
| #5329 | RunOnMethodBegin |
netcoreapp3.1 | 858ns | 0.876ns | 3.39ns | 0.00887 | 0 | 0 | 672 B |
| #5329 | RunOnMethodBegin |
net472 | 1.07μs | 1.04ns | 4.02ns | 0.1 | 0 | 0 | 634 B |
Member
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 (5329) (10.928M) : 0, 10927662
master (11.096M) : 0, 11096138
benchmarks/2.9.0 (10.743M) : 0, 10743092
section Automatic
This PR (5329) (7.430M) : 0, 7429964
master (7.482M) : 0, 7481686
benchmarks/2.9.0 (7.823M) : 0, 7823252
section Trace stats
This PR (5329) (7.904M) : 0, 7904001
master (7.944M) : 0, 7944133
section Manual
This PR (5329) (9.577M) : 0, 9577327
master (9.429M) : 0, 9429044
section Manual + Automatic
This PR (5329) (6.935M) : 0, 6935119
master (6.975M) : 0, 6975116
section Version Conflict
This PR (5329) (6.354M) : 0, 6353679
master (6.384M) : 0, 6383585
gantt
title Throughput Linux arm64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (5329) (9.589M) : 0, 9589189
master (9.571M) : 0, 9570993
benchmarks/2.9.0 (9.656M) : 0, 9656465
section Automatic
This PR (5329) (6.649M) : 0, 6648870
master (6.470M) : 0, 6469945
section Trace stats
This PR (5329) (6.927M) : 0, 6927415
master (7.095M) : 0, 7095354
section Manual
This PR (5329) (8.332M) : 0, 8331933
master (8.040M) : 0, 8039576
section Manual + Automatic
This PR (5329) (6.125M) : 0, 6124662
master (6.260M) : 0, 6259761
section Version Conflict
This PR (5329) (5.696M) : 0, 5695694
master (5.905M) : 0, 5905251
gantt
title Throughput Windows x64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (5329) (9.824M) : 0, 9824229
master (10.013M) : 0, 10013130
benchmarks/2.9.0 (9.967M) : 0, 9967407
section Automatic
This PR (5329) (6.854M) : 0, 6854040
master (7.046M) : 0, 7046320
benchmarks/2.9.0 (7.375M) : 0, 7374511
section Trace stats
This PR (5329) (7.243M) : 0, 7242879
master (7.437M) : 0, 7437175
section Manual
This PR (5329) (8.808M) : 0, 8807653
master (8.864M) : 0, 8864242
section Manual + Automatic
This PR (5329) (6.716M) : 0, 6715852
master (6.834M) : 0, 6834408
section Version Conflict
This PR (5329) (6.064M) : 0, 6064203
master (6.123M) : 0, 6122721
|
added 2 commits
March 21, 2024 14:34
kevingosse
changed the title
kevingosse
marked this pull request as ready for review
March 21, 2024 13:37
andrewlock
approved these changes
Mar 21, 2024
| // To future generations: if 100 is not enough, feel free to bump it up. We're really just checking that the value is "realistic". | ||
| actualNumberOfThreads.Should().NotBeNull().And.BeGreaterThan(0).And.BeInRange(expectedNumberOfThreads - 100, expectedNumberOfThreads + 100); | ||
| // A margin of 500 threads seem like a lot, but we have tests that spawn a large number of threads to try to find race conditions | ||
| actualNumberOfThreads.Should().NotBeNull().And.BeGreaterThan(0).And.BeInRange(expectedNumberOfThreads - 500, expectedNumberOfThreads + 500); |
Member
There was a problem hiding this comment.
Is this going to be safer? It feels like we're mostly just checking "is a number" here 😅
Suggested change
| actualNumberOfThreads.Should().NotBeNull().And.BeGreaterThan(0).And.BeInRange(expectedNumberOfThreads - 500, expectedNumberOfThreads + 500); | |
| actualNumberOfThreads.Should().NotBeNull().And.BeGreaterThanOrEqualTo(expectedNumberOfThreads ); |
Contributor
Author
There was a problem hiding this comment.
"Is a number bigger than 0 and not too crazy" 😛
Member
There was a problem hiding this comment.
not too crazy
expectedNumberOfThreads + 500 seems pretty crazy to me 😛
kevingosse
pushed a commit
that referenced
this pull request
Nov 21, 2024
## Summary of changes
Filter out the dead threads in the runtime metrics when using process
snapshot.
## Reason for change
We originally relied only on the count in the `PSS_THREAD_INFORMATION`
instance returned by `PssQuerySnapshot`. However, it does not only count
threads that are alive, but also dead threads which handle isn't closed
(the handle for dead managed threads is closed during finalization after
a garbage collection, so they can hang around for a while, especially
since threads tend to reach generation 2).
This can be demonstrated by this simple code:
```csharp
internal class Program
{
static void Main()
{
var threads = new Thread[50];
for (var i = 0; i < threads.Length; i++)
{
threads[i] = new Thread(() => Thread.Sleep(1));
threads[i].Start();
}
Thread.Sleep(1000);
ProcessSnapshotRuntimeInformation.GetCurrentProcessMetrics(out _, out _, out var threadCount, out _);
Console.WriteLine($"Thread count: {threadCount}");
}
}
```
With the old code, this would display 58, even thought the task manager
shows only 8 threads.
## Implementation details
We now use `PssWalkSnapshot` to walk the snapshot and filter out the
dead threads. I had to use a custom `FILETIME` struct to get the
alignment correct in both 32/64 bits. In hindsight, this might have
worked for `PSS_PROCESS_INFORMATION` as well (avoiding the need to have
separate `PSS_PROCESS_INFORMATION_32`/`PSS_PROCESS_INFORMATION_64`), I
might try to improve that in a future PR.
## Test coverage
The runtime metrics are already covered by tests. We don't test for dead
threads, but it seems hard to do in a reliable way (and I think we can
all agree our CI is flaky enough at the moment).
Also, the existing test has a tolerance of 500 threads. Back then I
couldn't explain why we got so much variation in the results, I guess
now we have a reasonable explanation (it was changed in
#5329, shortly after
adding PSS support).
Because we add additional calls for each thread, it has an impact on
performance so I ran some benchmarks.
With 50 threads (realistic):
```
| Method | Mean | Error | StdDev | Ratio | RatioSD |
|-------- |-----------:|---------:|---------:|------:|--------:|
| Process | 6,466.2 us | 71.57 us | 63.45 us | 63.15 | 9.80 |
| Old | 104.9 us | 5.67 us | 16.71 us | 1.02 | 0.23 |
| New | 127.1 us | 2.48 us | 2.65 us | 1.24 | 0.19 |
```
With 250 threads (extreme):
```
| Method | Mean | Error | StdDev | Ratio | RatioSD |
|-------- |-------------:|-----------:|-----------:|-------:|--------:|
| Process | 17,621.58 us | 349.413 us | 564.238 us | 183.31 | 20.11 |
| Old | 97.27 us | 3.801 us | 11.028 us | 1.01 | 0.16 |
| New | 129.39 us | 2.299 us | 2.823 us | 1.35 | 0.14 |
```
We're 25 to 35% slower, but we're still orders of magnitude faster than
using the .NET `Process` object.
## Other details
Fixes #6172
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary of changes
Increase the range of valid values for the number of threads in
RuntimeMetricsWriterTests.ShouldCaptureProcessMetrics.Reason for change
I initially thought that 100 was plenty enough, but we have tests that create a large number of threads to stresstest things (
UnmanagedMemoryPoolTestsfor instance). Let's hope that 500 is enough.