{"id":52883,"date":"2009-07-23T00:01:00","date_gmt":"2009-07-23T00:01:00","guid":{"rendered":"https:\/\/blogs.technet.microsoft.com\/heyscriptingguy\/2009\/07\/23\/hey-scripting-guy-how-can-i-test-the-efficacy-of-my-script-modifications\/"},"modified":"2009-07-23T00:01:00","modified_gmt":"2009-07-23T00:01:00","slug":"hey-scripting-guy-how-can-i-test-the-efficacy-of-my-script-modifications","status":"publish","type":"post","link":"https:\/\/devblogs.microsoft.com\/scripting\/hey-scripting-guy-how-can-i-test-the-efficacy-of-my-script-modifications\/","title":{"rendered":"Hey, Scripting Guy! How Can I Test the Efficacy of My Script Modifications?"},"content":{"rendered":"

 <\/font><\/p>\n

\"Hey,Hey Scripting Guy! I have a script that I wrote, and I am interested in modifying it to try and make it run faster. I know I can use the Measure-Object<\/b> Windows PowerShell cmdlet, but I want to run the script several times and get the average time it takes for each script to run. This task sounds like it might be a bit more complicated than I can handle because I am just beginning to learn Windows PowerShell. Could you possibly lend a hand?<\/p>\n

— JH<\/p>\n

\"Hey,Hello JH, <\/p>\n

It is late at night on a Saturday night, and I am finishing up the Hey, Scripting Guy! articles for the week that Craig will be on vacation. You see, Craig and I decided to write ahead so there would not be a disruption while we take our vacations. The Scripting Wife and I leave tomorrow morning to go to New York City for a week of shows and museums. Craig goes on vacation the following week (he’ll be running with the vampires on the Olympic Peninsula). Because it is rather late, I am drinking a nice ginger tea. When I make ginger tea, I use a piece of fresh ginger root, a stalk of lemongrass, and a teaspoon of orange blossom honey. I put everything in my tea pot and let it steep for 15 minutes before drinking. It is very relaxing and goes well with Dave Brubeck<\/font><\/a>. Because I am mellow, relaxed, and looking forward to a week of Broadway shows and museums, I am especially susceptible to suggestion. I will be glad to lend you a hand. The Test-TwoScripts.ps1 script, which I wrote for you, will allow you to test the performance of two scripts and will give you the results in a log file if you desire logged results. There is also a provision that will allow you to run your scripts multiple times to provide you with an average running time. <\/p>\n

The complete Test-TwoScripts.ps1 script is seen here. <\/p>\n

Test-TwoScripts.ps1<\/p>\n

<\/strong><\/p>\n

Param(
  <\/span>[string]$baseLineScript,
  <\/span>[string]$modifiedScript,
  <\/span>[int]$numberOfTests = 20,
  <\/span>[switch]$log
) #end param<\/p>\n

Function Test-Scripts
{
  <\/span>Param(
  <\/span>[string]$baseLineScript,
  <\/span>[string]$modifiedScript,
  <\/span>[int]$numberOfTests,
  <\/span>[switch]$log
) #end param
 <\/span>Measure-Command -Expression { $baseLineScript }
 <\/span>Measure-Command -Expression { $modifiedScript }
} #end Test-Scripts function<\/p>\n

Function Get-Change($baseLine, $modified)
{
  <\/span>(($baseLine – $modified)\/$baseLine)*100
} #end Get-Change function<\/p>\n

Function Get-TempFile
{
 <\/span>[io.path]::GetTempFileName()
} #end Get-TempFile function<\/p>\n

# *** Entry Point To Script
if($log) { $logFile = Get-TempFile }
For($i = 0 ; $i -le $numberOfTests ; $i++)
{
 <\/span>“Test $i of $numberOfTests” ; start-sleep -m 50 ; cls
 <\/span>$results= Test-Scripts -baseLineScript $baseLineScript -modifiedScript $modifedScript
 <\/span>$baseLine += $results[0].TotalSeconds
 <\/span>$modified += $results[1].TotalSeconds
 <\/span>If($log)
  <\/span>{
     <\/span>“$baseLineScript run $i of $numberOfTests $(get-date)” >> $logFile
     <\/span>$results[0] >> $logFile
     <\/span>“$modifiedScript run $i of $numberOfTests $(get-date)” >> $logFile
     <\/span>$results[1] >> $logFile
  <\/span>} #if $log
} #for $i <\/p>\n

“Average change over $numberOfTests tests”
“BaseLine: $baseLineScript average Total Seconds: $($baseLine\/$numberOfTests)”
“Modified: $modifiedScript average Total Seconds: $($modified\/$numberOfTests)”
“Percent Change: ” + “{0:N2}” -f (Get-Change -baseLine $baseLine -modified $modified)
if($log)
{
 <\/span>“Average change over $numberOfTests tests” >> $logFile
 <\/span>“BaseLine: $baseLineScript average Total Seconds: $($baseLine\/$numberOfTests)” >> $logFile
 <\/span>“Modified: $modifiedScript average Total Seconds: $($modified\/$numberOfTests)” >> $logFile
 <\/span>“Percent Change: ” + “{0:N2}” -f (Get-Change -baseLine $baseLine -modified $modified) >> $logFile
} #if $log
if($log) { Notepad $logFile }<\/p>\n

<\/font><\/font><\/font><\/p>\n

The first thing we do in the Test-TwoScripts.ps1 script is create the command-line parameters. The first parameter, baseLineScript<\/b>, is the path to the script that will be the baseline for comparison. Typically this is the script you used before you modified it. The second parameter is modifiedScript<\/b>, and it is the script whose changes you wish to evaluate. Note that these two scripts do not need to be related to one another. The third parameter is the numberOfTests<\/b> parameter. This number controls how many times the scripts will be run. This is because when testing, a script may run faster or slower on any given run. At times this may be due to files caching or other performance enhancements offered by the operating system, but at other times the difference may be due to resource contention or other anomalies. By running the scripts several times and averaging the results, a more accurate picture of the performance of the scripts can be gained. The last parameter is the switched log parameter. When the log parameter is present, it causes the script to write the performance information to a temporary text file that is displayed at the end of the completion of the script. The Param<\/b> section of the script is seen here:<\/p>\n

Param(<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>[string]$baseLineScript,<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>[string]$modifiedScript,<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>[int]$numberOfTests = 20,<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>[switch]$log<\/p>\n

<\/font><\/font><\/p>\n

) #end param<\/p>\n

<\/font><\/font><\/p>\n

The test-Scripts<\/b> function is used to call the Measure-Command<\/b> cmdlet for each of the two scripts to be tested. The Param<\/b> section of the function receives two inputs: the baseLineScript<\/b> parameter and the modifiedScript<\/b> parameter. These were cut and pasted from the Param<\/b> section to the script, because it was easier than typing everything a second time. Cutting and pasting the parameters also ensures that you avoid typing errors. This is shown here: <\/p>\n

Function Test-Scripts<\/p>\n

<\/font><\/font><\/p>\n

{<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>Param(<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>[string]$baseLineScript,<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>[string]$modifiedScript<\/p>\n

<\/font><\/font><\/p>\n

) #end param<\/p>\n

<\/font><\/font><\/p>\n

After the parameters for the Test-Scripts<\/b> function has been created, it is time to call the Measure-Command<\/b> cmdlet. The Measure-Command<\/b> cmdlet is called twice. The first time, the baseline script is passed to the expression parameter of the Measure-Command<\/b> cmdlet. The string that is passed to the $baseLineScript<\/b> parameter includes the full path to the script as well as all parameters the script requires to successfully execute. The second Measure-Command<\/b> cmdlet is called to evaluate the performance of the modified script. The path to the modified script as well as the parameters required to set up the command is passed to the expression parameter of the Measure-Command<\/b> cmdlet. This is seen here: <\/p>\n

 <\/span>Measure-Command -Expression { $baseLineScript }<\/p>\n

<\/font><\/font><\/p>\n

 <\/span>Measure-Command -Expression { $modifiedScript }<\/p>\n

<\/font><\/font><\/p>\n

} #end Test-Scripts function<\/p>\n

<\/font><\/font><\/p>\n

The Get-Change<\/b> function is used to calculate the percentage increase or decrease in total running time between the baseline script and the modified script. The baseline parameter contains the total number of seconds the baseline script required to execute. The modified parameter contains the total number of seconds the modified script required to execute. It the Test-Scripts<\/b> function was called several times (due to script performing multiple tests), the $baseLine<\/b> variable and the $modified<\/b> variable will contain the cumulative number of seconds running time from the entire series of tests. To calculate the percentage increase or decrease in total running time, the total number of seconds contained in the $modified<\/b> variable is subtracted from the total number of seconds contained in the $baseLine<\/b> variable. This number is then divided by the total number of seconds contained in the $baseLine<\/b> variable. The result of this computation is then multiplied by 100. The Get-Change<\/b> function is seen here: <\/p>\n

Function Get-Change($baseLine, $modified)<\/p>\n

<\/font><\/font><\/p>\n

{<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>(($baseLine – $modified)\/$baseLine)*100<\/p>\n

<\/font><\/font><\/p>\n

} #end Get-Change function<\/p>\n

<\/font><\/font><\/p>\n

After the Get-Change<\/b> function is created, the Get-TempFile<\/b> function is created. The Get-TempFile<\/b> function calls the static GetTempFileName<\/b> method from the Io.Path<\/b> .NET Framework class. The Get-TempFile<\/b> function is seen here: <\/p>\n

Function Get-TempFile<\/p>\n

<\/font><\/font><\/p>\n

{<\/p>\n

<\/font><\/font><\/p>\n

 <\/span>[io.path]::GetTempFileName()<\/p>\n

<\/font><\/font><\/p>\n

} #end Get-TempFile function<\/p>\n

<\/font><\/font><\/p>\n

After all the functions have been created, you arrive at the entry point to the script. The first thing to do is to see if the Test-TwoScripts.ps1 script was run with the –log<\/b> switched parameter. If it was launched with the –log<\/b> switched parameter, the $log<\/b> variable will exist. And if the $log<\/b> variable exists, the Get-TempFile<\/b> function is called and the resulting temporary file name is stored in the $logFile<\/b> variable. This is seen here:<\/p>\n

if($log) { $logFile = Get-TempFile }<\/span><\/p>\n

<\/font><\/font><\/p>\n

A for<\/b> loop is used to count the number of tests to perform on the scripts. The number of tests is stored in the $numberOfTests<\/b> variable. A status message is displayed in the Windows PowerShell console that indicates the test loop number. This section of the code is seen here: <\/p>\n

For($i = 0 ; $i -le $numberOfTests ; $i++)<\/p>\n

<\/font><\/font><\/p>\n

{<\/p>\n

<\/font><\/font><\/p>\n

 <\/span>“Test $i of $numberOfTests” ; start-sleep -m 50 ; cls<\/p>\n

<\/font><\/font><\/p>\n

After the loop progress message is displayed, the Test-Scripts<\/b> function is called. The Test-Scripts<\/b> function returns two System.TimeSpan<\/b> objects. These two objects are stored in the $results<\/b> variable. This is seen here: <\/p>\n

 <\/span>$results= Test-Scripts -baseLineScript $baseLineScript -modifiedScript $modifedScript<\/span><\/p>\n

<\/font><\/font><\/p>\n

Because the $results<\/b> variable contains an array of two TimeSpan<\/b> objects, you can index directly into the array and retrieve the value of the TotalSeconds<\/b> variable. Use [0]<\/b> to retrieve the first TimeSpan<\/b> object and [1]<\/b> to retrieve the second TimeSpan<\/b> object. The total seconds from the current test run is added to the total seconds that are stored in the $baseLine<\/b> and $modified<\/b> variables. This is seen here: <\/p>\n

 <\/span>$baseLine += $results[0].TotalSeconds<\/p>\n

<\/font><\/font><\/p>\n

 <\/span>$modified += $results[1].TotalSeconds<\/p>\n

<\/font><\/font><\/p>\n

If the script is run with the –log<\/b> switched parameter, the name of the script, the test number, and the results are written to the log file. The code that does this is seen here: <\/p>\n

 <\/span>If($log)<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>{<\/p>\n

<\/font><\/font><\/p>\n

     <\/span>“$baseLineScript run $i of $numberOfTests $(get-date)” >> $logFile<\/p>\n

<\/font><\/font><\/p>\n

     <\/span>$results[0] >> $logFile<\/p>\n

<\/font><\/font><\/p>\n

     <\/span>“$modifiedScript run $i of $numberOfTests $(get-date)” >> $logFile<\/p>\n

<\/font><\/font><\/p>\n

     <\/span>$results[1] >> $logFile<\/p>\n

<\/font><\/font><\/p>\n

  <\/span>} #if $log<\/p>\n

<\/font><\/font><\/p>\n

} #for $i <\/p>\n

<\/font><\/font><\/p>\n

After writing to the log file, it is time to display information to the Windows PowerShell console. The number of tests and the average time for each test run is displayed in the console for both the baseline and the modified scripts. The portion of the script that performs this action is shown here: <\/p>\n

“Average change over $numberOfTests tests”<\/p>\n

<\/font><\/font><\/p>\n

“BaseLine: $baseLineScript average Total Seconds: $($baseLine\/$numberOfTests)”<\/p>\n

<\/font><\/font><\/p>\n

“Modified: $modifiedScript average Total Seconds: $($modified\/$numberOfTests)”<\/p>\n

<\/font><\/font><\/p>\n

The percentage of change between the two scripts is calculated by using the Get-Change<\/b> function. The {0:N2}<\/b> format specifier indicates the percentage change to two decimal places. This is seen here: <\/p>\n

“Percent Change: ” + “{0:N2}” -f (Get-Change -baseLine $baseLine -modified $modified)<\/span><\/p>\n

<\/font><\/font><\/p>\n

The same information that was just displayed to the console is written to the log file if the script is launched with the –log<\/b> switched parameter. This section of the script is shown here: <\/p>\n

if($log)<\/p>\n

<\/font><\/font><\/p>\n

{<\/p>\n

<\/font><\/font><\/p>\n

 <\/span>“Average change over $numberOfTests tests” >> $logFile<\/p>\n

<\/font><\/font><\/p>\n

 <\/span>“BaseLine: $baseLineScript average Total Seconds: $($baseLine\/$numberOfTests)” >> $logFile<\/p>\n

<\/font><\/font><\/p>\n

 <\/span>“Modified: $modifiedScript average Total Seconds: $($modified\/$numberOfTests)” >> $logFile<\/p>\n

<\/font><\/font><\/p>\n

 <\/span>“Percent Change: ” + “{0:N2}” -f (Get-Change -baseLine $baseLine -modified $modified) >> $logFile<\/p>\n

<\/font><\/font><\/p>\n

} #if $log<\/p>\n

<\/font><\/font><\/p>\n

After the log file has been updated, it is displayed by using Notepad. The code that displays the log file in Notepad is seen here: <\/p>\n

if($log) { Notepad $logFile }<\/span><\/p>\n

<\/font><\/font><\/p>\n

The log that is produced is seen here:<\/p>\n

\"Image<\/span><\/p>\n


Well, JH, we hope you found our helping hand useful. The performance testing of scripts after they have been modified is a good way to see if your changes are good ones. Join us tomorrow as we reach into the virtual mail bag for Quick-Hits Friday. Follow us on Twitter<\/a> to stay up to date will all the latest news on the Script Center. You can also join our Facebook group<\/a> for similar purposes. Don’t forget about the Official Scripting Guys Forum<\/a> where thousands of dedicated scripters from all over the world meet to discuss scripts. Drop us an e-mail at scripter@microsoft.com<\/span><\/a> to let us know how things are going. Until tomorrow, have a great day!<\/p>\n


<\/span>Ed Wilson and Craig Liebendorfer, Scripting Guys<\/span><\/b><\/p>\n<\/h2>\n","protected":false},"excerpt":{"rendered":"

  Hey Scripting Guy! I have a script that I wrote, and I am interested in modifying it to try and make it run faster. I know I can use the Measure-Object Windows PowerShell cmdlet, but I want to run the script several times and get the average time it takes for each script to […]<\/p>\n","protected":false},"author":595,"featured_media":87096,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[1],"tags":[2,3,4,45],"class_list":["post-52883","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-scripting","tag-running","tag-scripting-guy","tag-scripting-techniques","tag-windows-powershell"],"acf":[],"blog_post_summary":"

  Hey Scripting Guy! I have a script that I wrote, and I am interested in modifying it to try and make it run faster. I know I can use the Measure-Object Windows PowerShell cmdlet, but I want to run the script several times and get the average time it takes for each script to […]<\/p>\n","_links":{"self":[{"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/posts\/52883","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/users\/595"}],"replies":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/comments?post=52883"}],"version-history":[{"count":0,"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/posts\/52883\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/media\/87096"}],"wp:attachment":[{"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/media?parent=52883"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/categories?post=52883"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/scripting\/wp-json\/wp\/v2\/tags?post=52883"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}