Recommended way to generate traces (dotnet-trace, perfview, etc)

[Cjewett]

I ended up creating this issue in the dotnet/diagnostics space dotnet/diagnostics#5649 but was hoping the folks maintaining this repository may have recommendations.

I'm trying to figure out why our test project is much slower in a containerized environment (k8s) by almost 10x when compared to local machines. I've tried using PerfView but ends up showing a bunch of Process64 testhost.net48 (49008) Args: --port 49057 --endpoint 127.0.0.1:049057 --role client --parentprocessid 96932 --datacollectionport 49546 --telemetryoptedin false lines and doesn't actually show me which tests or functions are being called when we're losing time. It's due to these being executed in a Thread which I guess PerfView doesn't do a great job tracking.

Do the maintainers of the Microsoft test framework have a recommended approach to tracing and profiling a test project from the CLI?

[Evangelink]

@Cjewett that's not your original question but I think moving out of VSTest to MTP might help. Taking a dump or using perfview is usually my approach.

@nohwnd @Youssef1313 @MarcoRossignoli any other solution?

[Youssef1313]

Agreed!

[nohwnd]

https://learn.microsoft.com/en-us/dotnet/core/diagnostics/debug-threadpool-starvation this is also a great page for thread pool starvation, and the section on perfview should correspond to what you will see if you select to collect thread time, and then go to threads view (or google how to diagnose thread pool starvation in perfview).

[Cjewett]

What is the number of logical processors you have on both machines? If you try to run locally and pause the debugger at multiple random points of the execution, do you see lots of threadpool threads that are waiting for any synchronous I/O, blocked on something, or doing any long synchronous operations? in which case that might be threadpool starvation, which is likely to get more apparent when running on a machine with smaller number of logical processors, especially on .NET Framework.

We're using Windows Nodes in Kubernetes with the following specs.
Node
64 CPU @ 4.0 GHz
256 GB RAM
5 TB NVMe

Pod
30 CPU
125 GB RAM
1 TB NVMe

As you can imagine a machine like this shouldn't really showcase any performance issues. I'm hoping the traces point toward a pretty obvious bottleneck because running the same test project on a local developers laptop or our older build machines not in Kubernetes w/ less and weaker resources completes the same test project in 8 minutes rather than 50 minutes. It's just been a bit of a battle trying to prove that and I'm trying to avoid peppering our code base with a bunch of debug statements. Although may have a team member do that soon as an extra data point.

[adc-cjewett]

I wasn't able to see the TestPlatform events for some reason. I'm guessing it has to do with the fact that I have to run PerfView at the Node level and then do some trickery in the Pod itself based on these instructions: microsoft/perfview#2344

Based on these screenshots I'm leaning towards some type of I/O issue I'll need to bring up with our k8s infrastructure maintainers. Figured I'd post here to get a second opinion though.

Command used: ./PerfView.exe "/DataFile:AlarmBusinessObjects7.etl" /BufferSizeMB:256 /StackCompression /CircularMB:2000 /ClrEvents:GC,Binder,Security,AppDomainResourceManagement,Contention,Exception,Threading,JITSymbols,Type,GCHeapSurvivalAndMovement,GCHeapAndTypeNames,Stack,ThreadTransfer,Codesymbols,Compilation /Providers:"*TestPlatform" /NoGui /FocusProcess:"testhost*.exe;datacollector*.exe;vstest.console*.exe;dotnet.exe" /NoNGenRundown /Merge:True /Zip:True /EnableEventsInContainers collect

[Cjewett]

Was able to work with some folks on our end to confirm I/O was the root cause of our performance issues and tracked it down to database operations against SqlLocalDb. Unclear why that performance is low when we expect it to be better but we're going through the motions of testing there.

Thank you all for your help! I marked @nohwnd's post below as the answer because it has instructions w/ pictures and believe that will help anyone else a lot if they come across this thread.

[nohwnd]

To clear things up, are you using windows containers or linux containers? Seeing that you mention perfview and .net framework, I am assuming windows?

For capturing the trace of vstest it is easiest to use perfview to collect whole system, with a process name filter testhost*.exe;datacollector*.exe;vstest.console*.exe;dotnet.exe:

You can also add *TestPlatform source to give you a time frame of when adapters start and stop.

Once you have the trace, I would start by looking at CPU stacks of all the processes that are coming from test platform (all vstest.console.exe / dotnet that runs vstest.console.dll, testhost.exe and datacollector.exe), and look at the timeline.

You can use the timestamps from Events to see when the run started and ended in testhost.

If that graph is very busy, then you are more likely running into CPU issues, if that graph is not busy, then this is more likely a thread starvation issue.

I would also try to generated some empty tests and run that in the containter setup you have and locally to see if the time changes as well, just to make sure this is issue in the platform, and not in your code.

Here is powershell code I use to generate tests for different frameworks: https://gist.github.com/nohwnd/3a05153f11b1a1eb6c3793311c25292d

[Cjewett]

Yeah this is a Windows Pod on a Windows Server 2022 node in Kubernetes. Thanks so much for the detailed instructions! Will test this out and report back ASAP.