How To Benchmark Scripts With PowerShell

The best possible performance of the code that we write is the must and this is the goal that we always want to achieve to the best of our abilities. Technology allows us to make solutions in many different approaches and to be able to assess which approach is the most efficient we need to benchmark our scripts.

Why We Need To Measure Performance Of Our PowerShell Scripts

We can write the code that works just fine but over the time we can “feel” or get the feedback that our code is performing less efficient and if we did not benchmark initially we do not have data to compare the current state with the initial state. Like I have written in the introduction we can have several approaches to solve the issue and it is best to benchmark each approach when deciding which one performs the best since the bear eya cannot always help us.

Development Phase

While we are in the developing phase of our code writing it is a good idea to benchmark our code especially at the end of this phase to have initial benchmark calibration so we can use it over the time in the production phase.

TIP: Just before I want to deploy my code from the test environment to the production environment I always benchmark the code using my own Measure-BenchmarksCmdLet CmdLet (that I will introduce later) and the results write in the script of the function just to have the evidence of the initial benchmark values.

Production Phase

When our scripts are in production it can happen that their performance deteriorates over time. If this happens then we should do the benchmarking again and if we have done initial benchmarking at the end of development we can compare the current state with the initial state.

TIP: For the most critical scripts it is smart to do benchmarking on a scheduled basis and follow the performance of these scripts, as soon as we notice a deterioration of values we should reassess our code.

How To Measure Your PowerShell Scripts Speed

After doing some research I have found three ways to measure PowerShell Scripts speed which can be used for benchmarking and each of them has their pros and cons:

1. Use Measure-Command PowerShell CmdLet
2. Use StopWatch .NET Class
3. Subtraction of two DateTime objects using Get-Date PowerShell CmdLet

Read the next section for examples of each way listed above.

Solutions For PowerShell Scripts Benchmarking

Let me show you some examples for each approach and discuss their pros and cons further. Personally, I was curious to see how will it perform one of my own CmdLets benchmarking with all three approaches. The results will be presented as the table in the conclusion section.

Solution 1: Measure-Command CmdLet

This approach using Measure-Command CmdLet is the easiest of three. If we run Get-Process CmdLet we will get all the process on the local machine and if we want to know how long it took for CmdLet to execute we just wrap that call within Measure-Command CmdLet like in the following example:

Measure-Command {Get-Process}

I can use the same approach for one of my own CmdLets (Get-CPUInfo):

Measure-Command {Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN"}

Here is the result of running the function call of Get-CPUInfo CmdLet using Measure-Command CmdLet approach:

As you can see a very easy and quick approach. The call to the function that we already have we just wrap around Measure-Command Script block and we are ready to get the execution time of our function call.

Solution 2: Stopwatch .NET Class

Using Stopwatch .NET Class is the most natural approach to us humans since it “looks and feels” like we have a stopwatch in our hands while benchmarking the code. However, it demands from us a little bit more work compared with the previous approach. Let me show you one example:

$StopWatch = New-Object System.Diagnostics.Stopwatch

$StopWatch.Start()

$obj = Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN"

$StopWatch.Stop()

Write-Host "Number of objects processed in PipeLine: " $obj.count
Write-Host "Time elapsed: " $StopWatch.Elapsed
Write-Host "Time elapsed in millisecondds: " $StopWatch.ElapsedMilliseconds

NOTE: If you want to test your own function call with this example just replace Get-CPUInfo call with your own and you will get execution time for your own function call.

As you can see from the example code above we need first to create a StopWatch object then we can start our benchmarking using the Start method and stop using the Stop method. If we want to know execution time we can use either Elapsed Property to get the result in “full-Time” format or ElapsedMilliseconds Property just to get the result in milliseconds.

Besides the methods used in this example, we have also StartNew method which will create a new instance of StopWatch object, sets the elapsed time property to zero, and starts measuring the elapsed time from that moment. Reset method will stop time interval measurement and reset the elapsed time property to zero. Restart method will do the same thing as the reset method and in addition, will start measuring elapsed time again but without creating a new instance of StopWatch object.

Here is the result of running Get-CPUInfo CmdLet call using StopWatch .NET Class approach:

Solution 3: Subtraction Of Two DateTime Objects

Subtraction of two DateTime objects approach is not as straightforward as using Measure-Command since we have to make two DateTime objects one before and one after the execution of the function that we want to benchmark and finally we find the difference between the two in order to get the execution time as we can see in the example code that follows.

$d1 = Get-Date        

$obj = Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN"

$d2 = Get-Date   

$diff = $d2 - $d1

$wmiCount = ($obj).Count
        
Write-Host "Script started at $d1"

Write-Host "Script finished at $d2"

Write-Host "Execution Time [hh:mm:ss:ms]:  $diff"

Write-Host "Total items processed: $wmiCount"

NOTE: If you want to benchmark your own code just replace Get-CPUInfo call with your own and you will get the result for your own code.

Here is the result of running Get-CPUInfo CmdLet call using Subtraction of two DateTime Objects:

Conclusion

We can compare the execution times of all three benchmark methods mentioned above and my own benchmark function Measure-BenchmarksCmdLet in the table below and see that execution times are very similar.

Measure-BenchmarksCmdLet CmdLet – Explained

I have written my own Measure-BenchmarksCmdLet CmdLet to help me benchmarking the scripts that I write. This CmdLet is part of the Efficiency Booster PowerShell Project. This project is the library of PowerShell CmdLets that helps IT experts in their everyday IT tasks.

In order to follow me along please download the source code from here.  Measure-BenchmarksCmdLet Function is part of the Utils module and the script file is in the 02utils folder.

Let me just quickly explain the CmdLet. Of the three approaches explained earlier this CmdLet uses the third one (Subtraction of two DateTime Objects) but I believe it can be easily rewritten to StopWatch .NET Class approach if needed.

The call to Measure-BenchmarksCmdLet CmdLet is very easy we just wrap the function call and that’s it. It is a very similar approach to the Measure-Command CmdLet when we think about easy to use aspect.

Here is the same function call that we have used in the previous examples and now using Measure-BenchmarksCmdLet CmdLet

Measure-BenchmarksCmdLet { Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" }

Here is the result of benchmarking using Measure-BenchmarksCmdLet CmdLet:

Input Parameters Of Measure-BenchmarksCmdLet Function

The Measure-BenchmarksCmdLet function has just two input parameters:

• $ScriptBlock that accepts the ScriptBlock data type.
• $errorlog, switch parameter that turns on/off logging of errors.

Here is the code for input parameters:

function Measure-BenchmarksCmdLet {
[CmdletBinding()]
param (
    [Parameter(Mandatory=$true)] 
    [ScriptBlock]$ScriptBlock,
    [Parameter( Mandatory=$false,
                HelpMessage="Write to error log file or not.")]
    [switch]$errorlog
)
}

INFO: The creation of input parameters for every function is a very important decision and I have written an article with many examples of parameters How To Create PowerShell Parameters Step By Step.

Begin, Process, End Blocks of Measure-BenchmarksCmdLet Function

The BEGIN and END input processing methods (blocks) are empty so I will focus on explaining the PROCESS block. Here is the explanation of the code in the PROCESS block:

• Set the start time in variable $d1 using Get-Date CmdLet.
• Use Invoke-Command CmdLet to execute the code that we want to benchmark.
• Set the end time in variable $d2 using Get-Date CmdLet.
• Get the execution time as the difference between end time and start time in variable $diff
• Get the number of objects processed in the PowerShell Pipeline just to have one more dimension of benchmarking (volume).

$d1 = Get-Date
        
$benchmark = $ScriptBlock
        
$obj = Invoke-Command -ScriptBlock $benchmark -ErrorAction Stop

$d2 = Get-Date   

$diff = $d2 - $d1
        
$wmiCount = ($obj).Count

Finally, we create the object using splatting to make the final result of benchmarking.

$properties = @{ 'Command'=$ScriptBlock;
                 'Started'=$d1;
                 'Finished'=$d2;
            	 '# of Objects processed'=$wmiCount;
            	 'Execution Time [hh:mm:ss:ms]'=$d2 - $d1;
            	 'Collected'=(Get-Date -UFormat %Y.%m.%d' '%H:%M:%S)}

$obj = New-Object -TypeName PSObject -Property $properties
$obj.PSObject.TypeNames.Insert(0,'Report.MeasureBenchmarks')

Write-Output $obj

INFO: If you want to know more about PowerShell Splatting concept when preparing parameters to be passed to CmdLet please read this article About Splatting.

In the last code snippet I would like you to notice the following line of code:

$obj.PSObject.TypeNames.Insert(0,'Report.MeasureBenchmarks')

This allows us to specify data type to objects that Measure-BenchmarksCmdLet CmdLet returns as a result instead to have default PSObject Data Type. We can check the data type of Measure-BenchmarksCmdLet CmdLet running the Get-Member CmdLet.

Measure-BenchmarksCmdLet { Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" } | Get-Member

We can see the data type marked red on the screenshot below.

I will discuss in Further Development And Improvements subheading why this is important in just a minute.

INFO: If you want to know more about Begin, Proces, and End input processing methods I have written the article PowerShell Function Begin Process End Blocks Explained With Examples.

Error Handling

All the code that we have discussed in previous sections has been wrapped in a try block in order to have the possibility of trapping the errors. In the catch block, we handle the errors writing them in an external Error Log text file. For writing errors in an external file, we can use my own Write-ErrorLog CmdLet.

    } catch {
        Write-Warning "Measure-BenchmarksCmdLet function failed."
        Write-Warning "Error message: $_"

        if ( $errorlog ) {

            $errormsg = $_.ToString()
            $exception = $_.Exception
            $stacktrace = $_.ScriptStackTrace
            $failingline = $_.InvocationInfo.Line
            $positionmsg = $_.InvocationInfo.PositionMessage
            $pscommandpath = $_.InvocationInfo.PSCommandPath
            $failinglinenumber = $_.InvocationInfo.ScriptLineNumber
            $scriptname = $_.InvocationInfo.ScriptName

            Write-Verbose "Start writing to Error log."
            Write-ErrorLog -hostname "Measure-BenchmarksCmdLet has failed" -errormsg $errormsg -exception $exception -scriptname $scriptname -failinglinenumber $failinglinenumber -failingline $failingline -pscommandpath $pscommandpath -positionmsg $pscommandpath -stacktrace $stacktrace
            Write-Verbose "Finish writing to Error log."
        } 
    }

INFO: Error handling is important in each programming language since no one likes programs with bugs. PowerShell is no exception to that and I have written an article on the subject with an example function that writes errors in external text file How To Log PowerShell Errors And Much More.

Regions Of Measure-BenchmarksCmdLet Function

I like to organize my code in regions using region and end region tags so when the code is collapsed I can see what the code is all about.

Measure-BenchmarksCmdLet is no exception to that rule and consist of three regions:

1. No region since this breaks functionality comment-based Help content.
2. Measure-BenchmarksCmdLet function “region”.
3. Execution examples region which contains different calls to the function.

INFO: If you want to learn how to write your own function help content please read How To Write PowerShell Help (Step by Step).

Further Development And Improvements

There are many possibilities for further improvements with benchmarking the code using Measure-BenchmarksCmdLet CmdLet.

I have already mentioned that Measure-BenchmarksCmdLet CmdLet returns as a data type Report.MeasureBenchmarks. This allows us to automate the saving of benchmark data in SQL Table with the same name as the data type.

Here are the next steps of improvement:

• We can schedule benchmarking of critical scripts on a regular basis.
• Benchmark data can be saved in the MS SQL Table with the same name as data type ( Report.MeasureBenchmarks ).
• We can use Microsoft Reporting Services to analyze benchmark data.
• Finally, we can work on the improvement of CmdLets, scripts, and functions that deteriorate in performance as soon as we notice that. Being proactive is really crucial in mission-critical solutions.

Useful Commands

How To Display Only Seconds For Measure-Command CmdLet

Here we have one example of how to show execution time in seconds of Measure-Command CmdLet:

Measure-Command {Get-Process} | Select-Object -Property TotalSeconds

Useful PowerShell Script’s Benchmark Articles

Here are some useful articles and resources:

• Measure-Command
• Invoke-Command
• Stopwatch Class

Measure-BenchmarksCmdLet – Source Code

DISCLAIMER: Measure-BenchmarksCmdLet function is part of the Efficiency Booster PowerShell Project and as such utilize other CmdLets that are part of the same project. So the best option for you in order for this function to work without any additional customization is to download the source code of the whole project from here.

Here is the source code of Measure-BenchmarksCmdLet CmdLet:

<#
.SYNOPSIS
This is quality control CmdLet to measure performance of differant Powershell CmdLets.

.DESCRIPTION
This is quality control CmdLet to measure performance of differant Powershell CmdLets.
As a result Measure-BenchmarksCmdLet shows, when CmdLet started (DD.MM.YYYY hh:mm:ss), 
how many objects CmdLet returned as result, 
when CmdLet finished (DD.MM.YYYY hh:mm:ss) 
and last info is differance (Diff) between start and end time in format: Hours:Minute:Seconds.Milliseconds

.PARAMETER ScriptBlock
Cmd-Let call that we want to measure performance for.
NOTICE: that this input parameter is Script Block type of parameter and writes between curly brackets { }

.PARAMETER errorlog
Switch parameter that sets to write to log or not to write to log. Error file is in PSLog folder with name Error_Log.txt.

.EXAMPLE
Measure-BenchmarksCmdLet { Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" -Verbose } 

Description
---------------------------------------
Benchmarking custom made Powershell CmdLet Get-CPUInfo with verbose logging.

.EXAMPLE 
Measure-BenchmarksCmdLet { Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" } 

Description
---------------------------------------
Benchmarking custom made Powershell CmdLet Get-CPUInfo without verbose logging.

.EXAMPLE 
Measure-BenchmarksCmdLet {Get-Service -ComputerName localhost}

Description
---------------------------------------
Benchmarking Powershell built-in CmdLet Get-Service for local computer.

.EXAMPLE
Help Measure-BenchmarksCmdLet -Full

Description
---------------------------------------
Test of Powershell help.

.INPUTS
ScriptBlock

Cmd-Let call that we want to measure performance for.

.OUTPUTS
System.String
System.TimeSpan

As a result Measure-BenchmarksCmdLet shows, when CmdLet started (DD.MM.YYYY hh:mm:ss), 
how many objects CmdLet returned as result, 
when CmdLet finished (DD.MM.YYYY hh:mm:ss) 
which command or CmdLet was running
when data were collected in date format (YYYY.MM.DD hh:mm:ss)
and last info is differance (Diff) between start and end time in: Hours:Minutes:Seconds.Milliseconds

.NOTES
FunctionName : Measure-BenchmarksCmdLet
Created by   : Dejan Mladenovic
Date Coded   : 10/31/2018 19:06:41
More info    : http://improvescripting.com/

.LINK 
How To Benchmark Scripts With PowerShell

Invoke-Command
Get-Date
#>
function Measure-BenchmarksCmdLet {
[CmdletBinding()]
param (
    [Parameter(Mandatory=$true)] 
    [ScriptBlock]$ScriptBlock,
    [Parameter( Mandatory=$false,
                HelpMessage="Write to error log file or not.")]
    [switch]$errorlog
)
BEGIN { 

}
PROCESS { 

    try {
    
        $benchmark = $ScriptBlock
        
        $d1 = Get-Date        
        
        $obj = Invoke-Command -ScriptBlock $benchmark -ErrorAction Stop

        #$wmiDT = [System.Management.ManagementDateTimeConverter]::ToDateTime($d1)    

        $d2 = Get-Date   

        $diff = $d2 - $d1
        
        $wmiCount = ($obj).Count

        Write-Verbose "Script started at $d1"
        Write-Verbose "Total items processed: $wmiCount"
        Write-Verbose "Script finished at $d2"

        #use this for debugging example
        #Write-Verbose $d2 - $d1

        Write-Verbose $diff

        Write-Verbose "Start processing Measure-BenchmarksCmdLet"

                $properties = @{ 'Command'=$ScriptBlock;
                                 'Started'=$d1;
                                 'Finished'=$d2;
            	                 '# of Objects processed'=$wmiCount;
            	                 'Execution Time [hh:mm:ss:ms]'=$d2 - $d1;
            	                 'Collected'=(Get-Date -UFormat %Y.%m.%d' '%H:%M:%S)}

                $obj = New-Object -TypeName PSObject -Property $properties
                $obj.PSObject.TypeNames.Insert(0,'Report.MeasureBenchmarks')

                Write-Output $obj
        
        Write-Verbose "Finish processing Measure-BenchmarksCmdLet"


    } catch {
        Write-Warning "Measure-BenchmarksCmdLet function failed."
        Write-Warning "Error message: $_"

        if ( $errorlog ) {

            $errormsg = $_.ToString()
            $exception = $_.Exception
            $stacktrace = $_.ScriptStackTrace
            $failingline = $_.InvocationInfo.Line
            $positionmsg = $_.InvocationInfo.PositionMessage
            $pscommandpath = $_.InvocationInfo.PSCommandPath
            $failinglinenumber = $_.InvocationInfo.ScriptLineNumber
            $scriptname = $_.InvocationInfo.ScriptName

            Write-Verbose "Start writing to Error log."
            Write-ErrorLog -hostname "Measure-BenchmarksCmdLet has failed" -errormsg $errormsg -exception $exception -scriptname $scriptname -failinglinenumber $failinglinenumber -failingline $failingline -pscommandpath $pscommandpath -positionmsg $pscommandpath -stacktrace $stacktrace
            Write-Verbose "Finish writing to Error log."
        } 
    } 

}
END { 
}
}
#region Execution examples
#Measure-BenchmarksCmdLet {Get-Service -ComputerName localhost} -errorlog -Verbose


#Measure-BenchmarksCmdLet { Import-Module 01common;  Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" -Verbose ; Remove-Module 01Common;}
#Measure-BenchmarksCmdLet { Import-Module 01common;  Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" ; Remove-Module 01Common;}

#Measure-BenchmarksCmdLet { Get-PrinterJob -computers "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" -Verbose | Where-Object { $_.JobStatus -like "Error*" } }

#Measure-BenchmarksCmdLet { Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" -Verbose }
#Measure-BenchmarksCmdLet { Get-CPUInfo -filename "OKFINservers.txt" -errorlog -client "OK" -solution "FIN" }
#endregion