MessageAnalyzer

All things about Message Analyzer and related diagnosis for Networks, Log files, and Windows Components

Using PowerShell to Automate Tracing

Using PowerShell to Automate Tracing

  • Comments 2
  • Likes

While tracing with a UI is simple, it has limitations today. When it comes to tracing a sticky problem, you need extensibility and flexibility in order to instrument when to start and stop a trace. We facilitate this in Message Analyzer by leveraging PowerShell and a new set of Cmdlets which ship with Message Analyzer which you can download from the Microsoft Download Center.

Getting Started with Help

PowerShell has built-in help and a facility to keep help files up to date. We leverage this system which means you need to tell PowerShell to update the help the first time you run. You do this by running the command “Update-Help – Force _Module *” from an administrative PowerShell prompt.

You can see a list of all the cmdlets by typing “help pef”. PEF stands for Protocol Engineering Framework, of which Message Analyzer is a part of. This result in the following list:

   1: PS> help pef
   2:  
   3: Name                              Category  Module                    Synopsis
   4: ----                              --------  ------                    --------
   5: Add-PefMessageProvider            Cmdlet    PEF                       Adds a message provider to a Trace Session.
   6: Invoke-PefCustomAction            Cmdlet    PEF                       Creates a PEF action that runs a script block.
   7: New-PefDateTimeTrigger            Cmdlet    PEF                       Creates a trigger that signals at the specifie...
   8: New-PefEventLogTrigger            Cmdlet    PEF                       Creates a trigger that signals when an event l...
   9: New-PefKeyDownTrigger             Cmdlet    PEF                       Creates a trigger that signals when a user pre...
  10: New-PefMessageTrigger             Cmdlet    PEF                       Creates a trigger based on detecting a filter ...
  11: New-PefProcessTrigger             Cmdlet    PEF                       Creates a trigger that signals when a process ...
  12: New-PefTimeSpanTrigger            Cmdlet    PEF                       Creates a trigger that signals after the speci...
  13: New-PefTraceSession               Cmdlet    PEF                       Creates a PEF trace session.
  14: New-PefWin32EventTrigger          Cmdlet    PEF                       Creates a trigger that signals when a specifie...
  15: Save-PefDataCollection            Cmdlet    PEF                       Saves the data from a PEF Trace Session.
  16: Set-PefTraceFilter                Cmdlet    PEF                       Sets a Trace Filter to a PEF Trace Session.
  17: Start-PefTraceSession             Cmdlet    PEF                       Starts a PEF Trace Session.
  18: Stop-PefTraceSession              Cmdlet    PEF                       Stops a PEF Trace Session.

Keep in mind this searches for anything with “pef” in the name, so you might see other non-related entries depending on what you have installed.

Simple Circular Capture

There are two ways to collect a trace, linear and circular. Linear means that you keep collecting data until you stop the trace. This is how the UI captures today. However, you can be limited by disk space in this scenario. Circular capture, on the other hand, lets you capture the most recent traffic while dropping older trace data as you exceed the maximum buffer size, which defaults to 100MB. You can use the TotalSize parameter to change this default. Using a circular trace lets you capture, potentially forever, and then stop the trace once the problem occurs. The only risk here is that the data you want to capture might roll off the end of the buffer if it is not set large enough.

Circular capture in the UI is currently problematic because of the way we show messages live as they arrive. While we have plans to support this in the future, using PowerShell is the only way to get a circular capture today. The general steps for any capture session consists of the following:

  1. Create a trace session using New-PefTraceSession. The returned session is used to pass to other cmdlets that require a session, like those to start and stop a trace session, like Start-PefTraceSession and Stop-PefTraceSession.
  2. Add providers to the session using Add-PefMessageProvider. Remember we leverage ETW (Event Tracing for Windows), so this is effectively adding any providers on the system, including the ones we ship for capturing NDIS, Firewall and HTTP Proxy traffic (see Network Capture is Dead blog for more info). Also note here that you can alternative specify a trace file path as input instead of a provider. This lets you process a trace, perhaps to apply a filter or to chop it up into smaller bits.
  3. An optional step it to decide when to stop the trace, using Stop-PefTraceSession. For instance, you can stop when a certain filter is met, for a specific amount of time, or when an Event Log message occurs. There are various types of triggers that can be included here as a stop criteria. But triggers can also be used in other situations, for instance when to start a trace.
  4. Start the capture using Start-PefTraceSession. So you might consider it odd to use the Stop cmdlet before you Start. However, the purpose of Stop is to define when to stop a trace. You need to specify that before you start because once the session is started you are blocked from entering any more commands.

So here are a list of commands to start a simple circular capture with a total size of 50MB. We add the PEF NDIS packet capture provider. The session is stopped by using a Ctrl+C, which is the default stopping mechanism.

   1: PS> $TraceSession01 = New-PefTraceSession -Mode Circular -Force -Path ".\Trace01.matu" -TotalSize 50 -SaveOnStop
   2:  
   3: PS> Add-PefMessageProvider -Session $TraceSession01 -Provider "Microsoft-PEF-WFP-PacketCapture"
   4:  
   5: PS> Start-PefTraceSession -Session $TraceSession01

The results of the trace is a .matu file, which stands for Message Analyzer Trace Unparsed. We save the data as unparsed because parsing takes time, and for these types of traces, speed is of the essence. You can save as parsed as well using the –SaveAsParsed flag, however this will slow things down during capture. On the other hand, loading a .matp file, which is the parsed format, is much faster. This is why it’s our default format when you save in the UI.

Triggers

The example above is pretty simple. But what if you want to control when a trace starts and stops, or decide to only apply a filter after some other event has occurred? The key to capturing something in a live environment is limiting how much data you capture. The ideal would be to let a capture run forever until some event happens. Triggers are the mechanism that allows you to get more concise about when to start and stop, which limits the data you need to capture and have to analyze. Let’s go over some of the triggers below:

  • New-PefDateTimeTrigger– Start/Stop/Save a trace at a specific time.
  • New-PefTimeSpanTrigger– Start/Stop/Save a trace after some time has passed, like 10 minutes.
  • New-PefEventLogTrigger– Start/Stop/Save a trace when a specific Event Log message occurs.
  • New-PefWin32EventTrigger – Start/Stop/Save a trace when a Win32 event is signaled. This is helpful because it provides an out of process way to control a trace.
  • New-PefKeyDownTrigger – Start/Stop/Save a trace when Ctrl+C is hit. Today, this cmdlet is fairly limited. In fact, PowerShell uses Ctrl+C to stop a running command by default.

Example: Trigger on an Event in the System Log

The following examples creates a circular capture that stops when Event 1234 occurs. The event source is a name we made up so that we could test this by issuing a unique command. This happens to be the example from the PowerShell help for New-PefEventLogTrigger.

   1: PS> $Trigger01 = New-PefEventLogTrigger -LogName "Application" -EventSourceName "PEFTestSource" -EventID 1234
   2:  
   3: PS> $TraceSession01 = New-PefTraceSession -Mode Circular -Force -Path "C:\Users\Admin\Documents\EventLog"
   4:  
   5: -TotalSize 50 -SaveOnStop
   6:  
   7: PS> Add-PefMessageProvider -Session $TraceSession01 -Provider "Microsoft-Pef-WFP-MessageProvider"
   8:  
   9: PS> Stop-PefTraceSession -Session $TraceSession01 -Trigger $Trigger01
  10:  
  11: PS> Start-PefTraceSession -Session $TraceSession01

To cause this trigger to get hit, you can manually insert an event log message using the following PowerShell commands from an elevated PowerShell prompt. More likely you’d be waiting for an event that you don’t make up, but this will let you test the functionality, since it’s not always easy to make a specific event fire.

   1: PS> New-EventLog -Logname Application -Source PEFTestSource
   2:  
   3: PS> Write-EventLog -Logname Application -Source PEFTestSource -eventId 1234 -Entrytype Information 

Example: Issue a custom event trigger

So, you want to cause virtually anything to happen when you see an expression or pattern? No problem – because with embedded PowerShell scripting, almost anything is possible. Keep in mind the practical limitations of processing power and memory. With this cmdlet you basically have the ability to run a PowerShell script as the result of a trigger.

For this example, we simply print out every time we see an ICMP message. The “New-PefMessageTrigger” issues a filter that matches any module equal to ICMP. The resulting @sb object is executed.

[Update] TIP: make sure to use ping with the /4 option to force ICMP vs ICMPv6.

   1: PS> $t = New-PefKeyDownTrigger -CtrlC
   2:  
   3: PS> $sb = { $Host.UI.WriteErrorLine("ICMP found") }
   4:  
   5: PS> $s = New-PefTraceSession -Mode Linear -SaveOnStop -Path "C:\users\paul\documents\Simple" -Force -SaveAsParsed
   6:  
   7: Add-PefMessageProvider -Session $s -Provider Microsoft-Pef-WFP-MessageProvider
   8:  
   9: PS> $t2 = New-PefMessageTrigger -Session $s -Filter "ICMP" -Repeat
  10:  
  11: Invoke-PefCustomAction -Script $sb -Trigger $t2
  12:  
  13: PS> Stop-PefTraceSession -Session $s -Trigger $t
  14:  
  15: PS> Start-PefTraceSession -s $s 

Example: Triggering by an external event

Sometimes you want to trigger an event programmatically and across process. We leverage Windows Win32 Events to do this. This example listens for an event called MyEvent to be signaled.

   1: PS> $t = New-PefWin32EventTrigger -EventName MyEvent -CheckTimerPeriodMs 5
   2:  
   3: PS> $s = New-PefTraceSession -Name TestEventLogEventScenario -Mode Linear -SaveOnStop -Path C:\users\paul\documents\Win32Event -Force 
   4:  
   5: Add-PefMessageProvider -Session $s -Provider Microsoft-Pef-WFP-MessageProvider 
   6:  
   7: PS> Stop-PefTraceSession -Session $s -Trigger $t 
   8:  
   9: PS> Start-PefTraceSession -Session $s 

I used the following script to signal the event, but you can imagine that there are many ways you can set a Win32 event programmatically or even remotely.

   1: $source = @"
   2:  
   3: using System.Threading;
   4: using System;
   5:  
   6: public class Win32Event
   7: {
   8:  
   9:   EventWaitHandle ewh;
  10:  
  11:   public Win32Event(string s)
  12:   {
  13:        Console.WriteLine(s); 
  14:        ewh = new EventWaitHandle(false, EventResetMode.AutoReset, s);
  15:   }
  16:  
  17:   public void Set()
  18:   {
  19:       Console.WriteLine("set");       
  20:  
  21:       ewh.Set();
  22:   }
  23:  
  24:   public void Reset()
  25:   {
  26:        Console.WriteLine("reset"); 
  27:        ewh.Reset();
  28:   }
  29:  
  30:   public void SetAndReset()
  31:   {
  32:         ewh.Set();
  33:         Thread.Sleep(500);
  34:         ewh.Reset();
  35:   }  
  36: }
  37:  
  38: "@
  39:  
  40: Add-Type -TypeDefinition $source  -Language CSharp
  41:  
  42: [string]$eventName = $args[0]
  43:  
  44: if($args.Count -eq 0)
  45: {
  46:   $eventName = "MyEvent"
  47: }
  48:  
  49: $testobj = New-Object -TypeName Win32Event($eventName)
  50: $testobj.SetAndReset() 

Script for Any Situation

PowerShell is flexible because of how the commands are designed to integrate with each other. The versatility is endless. And, as always, please visit the relevant documentation online for PowerShell for more detail. As we continue to evolve PowerShell and Message Analyzer we hope to make it easier to capture, and in the future analyze, in an automated fashion.

More Information

For a brief synopsis of the PowerShell cmdlets provided with Message Analyzer, along with versioning requirements and additional information about how to access the cmdlets and help, see the following topic from the Message Analyzer Operating Guide on TechNet:

Automating Tracing Functions

Comments
  • Pure Awesomeness!

  • Not good

Your comment has been posted.   Close
Thank you, your comment requires moderation so it may take a while to appear.   Close
Leave a Comment