Click here to monitor SSC

James Gilmore is a software tester at Red Gate.

Profiling PowerShell cmdlets with ANTS Performance Profiler

Published 13 March 2013 6:35 pm

Following the early lead of Exchange Server 2007, Citrix’s XenDesktop SDK (which I was fortunate enough to work on), and now the Azure platform, PowerShell is being used more and more to provide the scriptable interface to proprietary systems.

At Red Gate I’m usually profiling cmdlets to test the profiler itself – PowerShell is a great test case – but we know some of our users are cmdlet authors who want to know whether their code is performing as well as it should. PowerShell provides a timing function called Measure-Command, and of course it’s possible to instrument a script manually with StopWatch objects, but developers need to dig into their C# code, not the PowerShell script which invokes it.

Because powershell.exe is itself a .NET application, ANTS Performance Profiler can handle this. Profile the PowerShell executable with the command line arguments configured to load your module and run the cmdlet.

-command "import-module .\ANTSCmdlets.psd1; Read-Host; Get-PopularPosts; Read-Host;"

Starting PowerShell is CPU intensive, so I’ve put a Read-Host (the equivalent of Console.ReadLine) in my script to separate this noise from the time period I’m interested in, and another one at the end to give me time to read any exception messages.

  1

For this example, I’ve got a cmdlet that will return a collection containing the most popular forum posts from The Beerhouse MVC web application. It does this by connecting to the backend database and running a SQL query.

[Cmdlet(VerbsCommon.Get, "PopularPosts")]
public class PopularPostsCmdlet : Cmdlet
{
[Parameter(HelpMessage = "The minimum number of views a post must have to be considered popular")]
	public int MinimumViewCount = 10;

	private IEnumerable<KeyValuePair<int, string>> PopularPosts()
	{
		var popularPosts = new List<KeyValuePair<int, string>>();

		using (var connection = new SqlConnection(@"Server=.\SQL2008;Integrated Security=SSPI"))
		{
			connection.Open();
			var command = new SqlCommand("SELECT PostID,Title FROM [Beerhouse].[TheBeerHouse].[Posts] WHERE ViewCount >= @minViews", connection);
			command.Parameters.Add(new SqlParameter("minViews",MinimumViewCount));
			using (var reader = command.ExecuteReader())
			{
				while (reader.Read())
				{
					popularPosts.Add(new KeyValuePair<int, string>(reader.GetInt32(0), reader.GetString(1)));
				}
			}
		}

		return popularPosts;
	}

	protected override void ProcessRecord()
	{
		foreach(var kvp in PopularPosts())
		{
			WriteObject(kvp);
		}
	}
}

2

This is pretty naïve code, but it serves to illustrate what we can expect from cmdlet profiling. Here’s the screenshot from ANTS:

3

Because the assembly which defines my cmdlet has the PDB in the same directory, ANTS has picked up the path to the source code and highlighted methods with source in bold. I’ve selected the PopularPosts node, and ANTS shows the source code in the panel below. It’s also picked out my SQL statement, and tells me that it took 149ms to run. That’s not bad, but if I wanted better performance over multiple runs I should probably be caching the SQL Server connection.

4

APP 8 spoiler alert!

A new feature in APP8 is the ability to instrument outgoing HTTP requests, such as calls to web services. In my second example cmdlet, Get-RedGateWebpage, I download a web page to illustrate this.

[Cmdlet(VerbsCommon.Get,"RedGateWebpage")]
public class RedGateWebpageCmdlet : Cmdlet
{
	protected override void ProcessRecord()
	{
		string webPage;

		using(var webClient = new System.Net.WebClient())
		{
			webPage = webClient.DownloadString("http://www.red-gate.com/");
		}

		WriteObject(webPage);
	}
}

As before, ANTS shows me how much time was spent in ProcessRecord, and attributes it to the ~400ms spent downloading the web page.

 5

One Response to “Profiling PowerShell cmdlets with ANTS Performance Profiler”

  1. James Gilmore says:

    Clarification

    ANTS Performance Profiler can’t profile Powershell at a script level (sorry!). PoSH is a language implemented in .NET, not a ‘.NET language’ in the way that C# and VB.NET are.

    We can profile what happens in .NET, but it no longer relates to the original powershell script text in a simple way. Obviously there will be clues if you look hard enough, because there’s a very close mapping between powershell and .NET functions, but it’s not going to give you hit counts on your powershell functions or anything like that. In that sense, scripts are not supported.

    However, profiling your powershell script isn’t futile, because you’ll still get SQL, HTTP and file IO data, and a hint at what operations are taking a long time.

Leave a Reply