PowerShell Pipeline

Timing PowerShell Automations

Get an accurate measurement of how long it takes to run a specific or set a timer for your script to run with these two tips.

Suppose that you wanted to figure out how long a certain operation took within a script or you wanted to time multiple parts of a script or function in PowerShell. How might you do that? Or perhaps you wanted to run a certain command or perform an operation every 10 seconds without having a loop running that just slept for a set amount of seconds. Today I will take a look at two very different types of timing approaches and show you how they can work for you.

Stopwatch and PowerShell
PowerShell has access to all of the great things that come with .Net to do things that natively it just cannot do. One of those things happens to be System.Diagnostics.Stopwatch which allows us to create our own stopwatch to time how long things run. To create a stopwatch object, we simply use New-Object and supply the type and away we go!

$StopWatch = New-Object -TypeName System.Diagnostics.Stopwatch 

Looking at the default properties of the object, we can see whether or not the stopwatch is currently running, the current elapsed time as well as the elapsed milliseconds and ticks.

[Click on image for larger view.]  Figure 1. Displaying the stopwatch object properties.

Now we will make use of Get-Member to look at the available methods available to use.

PS C:\users\boepr\desktop> $StopWatch | Get-Member

   TypeName: System.Diagnostics.Stopwatch

Name                MemberType Definition                    
----                ---------- ----------                    
Equals              Method     bool Equals(System.Object obj)
GetHashCode         Method     int GetHashCode()             
GetType             Method     type GetType()                
Reset               Method     void Reset()                  
Restart             Method     void Restart()                
Start               Method     void Start()                  
Stop                Method     void Stop()                   
ToString            Method     string ToString()             
Elapsed             Property   timespan Elapsed {get;}       
ElapsedMilliseconds Property   long ElapsedMilliseconds {get;}
ElapsedTicks        Property   long ElapsedTicks {get;}      
IsRunning           Property   bool IsRunning {get;}

The methods that are the most interesting are in bold. The Start and Stop methods are self-explanatory in that they Start and Stop the stopwatch. The Restart method will reset the elapsed time back to its original starting point and start the stopwatch again. Reset will stop the stopwatch and set the elapsed time back to its original starting point.

I'll go ahead and start the stopwatch using Start() and then look at the object during a few seconds of its run.

[Click on image for larger view.]  Figure 2. Starting and tracking the current elapsed time.

We can see how the IsRunning is set to $True and the Elapsed* properties continue to increase as the stopwatch continues to run.

I can then call Stop() and this will halt the stopwatch from running.

[Click on image for larger view.]  Figure 3. Stopping the stopwatch.

When looking at the Elapsed property, what you actually see if different than how it appears in the StopWatch object as it is a TimeSpan object, not the string that you actually see. What is happening is the TimeSpan object is being cast as a string when displayed in the Stopwatch object Elapsed property. We can force the display of the Elapsed property by calling the ToString() method.

 

PS  C:\users\boepr\desktop> $StopWatch.Elapsed
Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 10
Milliseconds      : 250
Ticks             : 102504161
TotalDays         : 0.000118639075231481
TotalHours        : 0.00284733780555556
TotalMinutes      : 0.170840268333333
TotalSeconds      : 10.2504161
TotalMilliseconds : 10250.4161
PS C:\users\boepr\desktop> $StopWatch.Elapsed.ToString()
00:00:10.2504161

Using the StopWatch, you could create the object at the beginning of your function or script and then kick it off and as you pass various lines of your script, you can either display the current time of the stopwatch and then restart it or allow it to continue to display the time at another part of the script. Whatever you want to do with it, it can be a great tool in debugging performance of a script.

Timer and PowerShell
The next timing object that we are going to look at is the use of Timers.Timer object, which presents a way to run commands during each interval of the timer by use of an event.

We'll build the Timer object again using New-Object and then take a look at the initial properties as well as the available methods and events on this object. The events that we will be looking will play an important part once we get going with it.

$Timer = New-Object -Type Timers.Timer 
[Click on image for larger view.]  Figure 4. Looking at the Timer object properties.

Here we see that the interval is currently 100 milliseconds and that it is currently not enabled. A look at the methods and events shows some more useful things. We can set the Interval to any particular time that we want, whether it is 1000 milliseconds or an hour. Just remember that the time inputted has to be in milliseconds so make sure that you make those calculations.

PS  C:\users\boepr\desktop> $Timer | Get-Member

   TypeName: System.Timers.Timer

Name                      MemberType Definition                               
----                      ---------- ----------                               
Disposed                  Event      System.EventHandler Disposed(System.Obj...
Elapsed                   Event      System.Timers.ElapsedEventHandler Elaps...
BeginInit                 Method     void BeginInit(), void ISupportInitiali...
Close                     Method     void Close()                             
CreateObjRef              Method     System.Runtime.Remoting.ObjRef CreateOb...
Dispose                   Method     void Dispose(), void IDisposable.Dispose()
EndInit                   Method     void EndInit(), void ISupportInitialize...
Equals                    Method     bool Equals(System.Object obj)           
GetHashCode               Method     int GetHashCode()                        
GetLifetimeService        Method     System.Object GetLifetimeService()       
GetType                   Method     type GetType()                            
InitializeLifetimeService Method     System.Object InitializeLifetimeService()
Start                     Method     void Start()                             
Stop                      Method     void Stop()                              
ToString                  Method     string ToString()                        
AutoReset                 Property   bool AutoReset {get;set;}                
Container                 Property   System.ComponentModel.IContainer Contai...
Enabled                   Property   bool Enabled {get;set;}                  
Interval                  Property   double Interval {get;set;}               
Site                      Property   System.ComponentModel.ISite Site {get;s...
SynchronizingObject       Property   System.ComponentModel.ISynchronizeInvok...

For the methods, Start and Stop are the most important because they are what allow us to control the timer. On the events side, we are looking at Elapsed the closest. This is because we can tie in a registration using Register-ObjectEvent to that particular Event and set an Action scriptblock that will run every time the interval has been reached on the Timer which will fire its Elapsed event.

With that, let's show off an example of doing this by displaying a simple message whenever the interval is reached.

$Timer = New-Object -Type Timers.Timer
$Timer.Interval = 5000 #5 seconds
Register-ObjectEvent -InputObject $Timer -EventName Elapsed -SourceIdentifier TimerEvent -Action {
Write-Host "[$(Get-Date)] Timer interval elapsed!"
}
[Click on image for larger view.]  Figure 5. The PSJob that will handle the event.

We can see from the outputted job object that we have created our event handler. Note that this will not show running until after the first event is fired. Speaking of events, this can also be verified by looking at the registered event using Get-EventSubscriber.

PS  C:\users\boepr\desktop> Get-EventSubscriber
SubscriptionId   : 1
SourceObject     : System.Timers.Timer
EventName        : Elapsed
SourceIdentifier : TimerEvent
Action           : System.Management.Automation.PSEventJob
HandlerDelegate  :
SupportEvent     : False
ForwardEvent     : False

We can either call Start() or set the Enabled state to $True to kick off the timer. Stopping the timer works the opposite way by calling Stop() or setting Enabled to $False. Once you kick off the timer, after five seconds we will see our first notification on the screen and again after another five seconds and so on until we stop the timer.

[Click on image for larger view.]  Figure 6. Each interval firing an event that displays a message.

When I am completely finished with this, I can do some cleanup by unregistering the event handler and remove the PSJob.

Get-EventSubscriber | Unregister-Event
Get-Job | Remove-Job

With that we now have a couple of ways to work with timing in PowerShell.

comments powered by Disqus
Most   Popular