vstest.console

nesher_hh

Is it possible to profile the tests running in vstest.executionengine.exe?
I have problems with unmanaged memory. That mean I can't just attach to this process, as ANTS Memory Profile does not allow me to profile unmanaged memory in attached processes.

Jessica R

Hi!

You can profile the unmanaged memory by running the tests with vstest.console.exe and starting the process through the profiler.

To do this, you'll need to profile using the ".NET Executable" option and point the profiler to the vstest.console.exe, with a command line argument that is the path to the testing DLL. For example:

Path to .NET Executable: C:Program Files (x86)Microsoft Visual Studio 12.0Common7IDECommonExtensionsMicrosoftTestWindowvstest.console.exe
Command line arguments: "C:Usersjessica.ramosDocumentsVisual Studio 2012ProjectsConsoleApplication32UnitTestProject1inDebugunittestproject1.dll"

(for the similar steps on profiling with MSTest, kindly see here: https://documentation.red-gate.com/disp ... +in+MSTest)

I hope this helps! Please let me know if you have any other questions.

nesher_hh

This doesn't work because vstest.console starts child process vstest.executeengine.exe that runs the tests. But memory profile just profiles the vstest.console and not the vstest.executeengine. Mstest runs the tests itself.

Jessica R

Hi there,

You can actually profile the vstest.executionengine.exe that is launched by enabling the "Profile child processes" option (under "Additional profiler options") before starting the session--can you kindly give this a try?

Please let me know how you get on!

nesher_hh

I have already did this. But for some reason Profile does not make this. It does not show memory increase on the graphic. Does it mean that it still profiles the other process?

Jessica R

Ah I see, many thanks for clarifying! If "profile child processes" is enabled, it will indeed profile any other process launched by vstest.console.exe

I should note though, I don't do much testing myself but I noticed that I when I do launch tests this way, they are ran by vstest.console.exe itself. Just to confirm, if you use Process Explorer and check the RedGate.MemoryProfiler.UI.exe instance, and then see it's vstest.console.exe child process, does it have vstest.executionengine.exe as a child process (I'm not sure if it won't launch it if it's already running from Visual Studio)? You'll need to be viewing in tree mode - View>Show process tree

If it was definitely launched by vstest.console though, there should be a process drop-down menu under the profiler timeline where you can choose which process to see results for. For example:



Since the timeline isn't showing an increase though, can I also just check--does the console window show that the tests are executing successfully? if so, if you look at the class list, do you see objects used by the tests there? (I'm wondering if the issue may just be that the timeline isn't working due to broken performance counters, and the profiler is still actually gathering the results.)

nesher_hh

Oh, I see. I have to press "Take memory snapshot" before drop-down will appear. Sadly it shows only vstest.discoveryengine.x86.exe. This process is used to discover which tests are there in assemblies. Then the vstest.executionengine.x86.exe is started as a child process of vstest.console.exe (It appears as a child in Process Explorer). But it does not shown in drop-down.

Jessica R

Hi!

Hm you should still see results for vstest.executionengine.x86.exe if it's launched by vstest.console.exe or one of its child processes. Can I just double check--once the vstest.executionengine.x86.exe process was for sure launched, did you try taking another snapshot? You'll need to have taken a snapshot where it was already launched in order to see it in the results. Please let me know!

nesher_hh

Yes, I did a new snapshot after vstest.executionengine.x86.exe. But it didn't appear in the drop-down list.

Jessica R

Hiya,

I was able to get my test project to run in the vstest.executionengine.exe process by adding other command line options, but when I profiled, all three processes (vstest.console, vstest.discoveryengine and vstest.executionengine) did appear in the drop-down list, so I still got the memory results for the tests.

Via the support call we have open for you (#54847), can you kindly:
- Send across your log files (Help>Open log folder)
- Save your results and send them across

Those will hopefully shed more light. Thank you!

Jessica R

Can you also please check Event Viewer (Windows log>application) for any errors regarding the profiler or the vstest.executionengine.x86.exe process? That may give more details in case another profiler or something else is stopping ANTS from hooking into the process.

Thank you!

nesher_hh

There is no error regarding vstest.executionengine.x86.exe in Event Viewer. The log of ANTS inlcludes this:

10 Dec 2015 08:31:55.872 [8] INFO RedGate.Profiler.Engine.Startup.Sessions.BaseSession - Starting 'C:Program Files (x86)Microsoft Visual Studio 14.0Common7IDECommonExtensionsMicrosoftTestWindowvstest.console.exe'
10 Dec 2015 08:31:55.997 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Process ID 0x1224 'C:Program Files (x86)Microsoft Visual Studio 14.0Common7IDECommonExtensionsMicrosoftTestWindowvstest.console.exe' has connected.
10 Dec 2015 08:31:55.997 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Suggesting that target write to C:UsersdanielAppDataLocalRed GateANTS Memory Profiler 8Results mp1bc0_8d30138999a2005_a
10 Dec 2015 08:31:56.059 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Connected and receiving data through C:UsersdanielAppDataLocalRed GateANTS Memory Profiler 8Results mp1bc0_8d30138999a2005_a.
10 Dec 2015 08:31:57.838 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Process ID 0x174c 'C:Program Files (x86)Microsoft Visual Studio 14.0Common7IDECommonExtensionsMicrosoftTestWindowvstest.discoveryengine.x86.exe' has connected.
10 Dec 2015 08:31:57.838 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Suggesting that target write to C:UsersdanielAppDataLocalRed GateANTS Memory Profiler 8Results mp1bc0_8d30138999a2005_b
10 Dec 2015 08:31:57.900 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Connected and receiving data through C:UsersdanielAppDataLocalRed GateANTS Memory Profiler 8Results mp1bc0_8d30138999a2005_b.
10 Dec 2015 08:32:32.567 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Retrying read of 0-length message
10 Dec 2015 08:32:33.019 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Profiled process indicates that it has completed snapshot 0
10 Dec 2015 08:32:33.019 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Profiled process indicates that it has completed snapshot 0
10 Dec 2015 08:32:35.688 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Retrying read of 0-length message
10 Dec 2015 08:32:36.000 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Profiled process indicates that it has completed snapshot 1
10 Dec 2015 08:32:36.000 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Profiled process indicates that it has completed snapshot 1
10 Dec 2015 08:32:56.702 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Retrying read of 0-length message
10 Dec 2015 08:32:57.014 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Profiled process indicates that it has completed snapshot 2
10 Dec 2015 08:32:57.014 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Profiled process indicates that it has completed snapshot 2
10 Dec 2015 08:33:16.717 [Profiler pipe monitor] WARN RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Pipe has been closed; most likely the process being profiled has terminated.
10 Dec 2015 08:33:16.717 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.Pipe - Recycling pipe
10 Dec 2015 08:33:16.733 [12] INFO RedGate.Profiler.Engine.Startup.Sessions.BaseSession - Process vstest.console has finished.
10 Dec 2015 08:33:17.029 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Profiled process indicates that is shutting down in an orderly manner
10 Dec 2015 08:33:17.045 [Profiler pipe monitor] WARN RedGate.Profiler.Engine.Startup.Basic.PipeConnection - Pipe has been closed; most likely the process being profiled has terminated.
10 Dec 2015 08:33:17.045 [Profiler pipe monitor] INFO RedGate.Profiler.Engine.Startup.Basic.Pipe - Recycling pipe
10 Dec 2015 08:33:17.045 [43] INFO RedGate.Profiler.Engine.Startup.Sessions.BaseSession - Process has finished.

Nothing about executionengine

Jessica R

Ah okay, thanks for checking that. In that case, can you kindly send across your results file and also gather a Procmon trace for us to take a look at:

- Please download Microsoft's procmon (if you don't have it already - http://technet.microsoft.com/en-us/sysi ... 96645.aspx)
- Extract the files and run procmon.exe
- Start the profiler and let the issue with vstest.executionengine.x86.exe occur
- Please then go back to procmon, go to File>Save, and send across this pml results file (save the trace with All Events)
- Please also go back to the profiler, save, and send in your results file (ending in .amp8results)

You can then send the files to us by signing into our support site (at https://redgatesupport.zendesk.com with the same email address you've registered for the forums with - you may need to first register on the support site as well) and attaching them to a ticket update for ticket #54847.

Thank you!

larsGW

Hi,
Did you find a solution for this issue? I'm in a similar situation and have followed the guide for the ANTS Profiler with out luck.

Regards Lars