Summary: Microsoft Scripting Guy, Ed Wilson, talks about using Get-WinEvent in Windows PowerShell with FilterXML to parse event logs.

Microsoft Scripting Guy, Ed Wilson, is here. Today I am sipping a cup of English Breakfast tea. In my pot, I decided to add a bit of spearmint, peppermint, licorice root, lemon peel, orange peel, and lime peel to the tea. The result is a very refreshing cup of tea with a little added zing.

XML adds zing to event log queries

The other day when I opened the event log on my laptop, I noticed all the red stop signs, and I thought, "Dude, I really need to investigate this."

I decided to look at the application hangs. Although I can use the Event Viewer to filter for application hang, errors, and event ID 1002, that is as far as I can go by default. To see what application is hanging, I need to go into the message details box. This is a manual process and it is shown here:

It is possible to improve this situation, and to filter only on a specific application. This is because the data is stored in the Event Data portion of the message. This section appears when I select XML View from the Details tab, as shown here:

I can use this information to create a custom XML query by clicking Filter Current Log, clicking XML, and then clicking the Edit query manually check box. This is shown here:

In fact, this process outlines my process for creating a custom XML filter to filter the event log. I select as much as I need by using the graphical tools, then I edit the XML query manually in the dialog box. The advantage is that if I do not get the query correct, it does not display any records, it displays the incorrect records, or it tells me my query is invalid. At least that is what happens to me.

But I do not directly edit the query in the dialog box because if I get it wrong the first time, I have messed up my query. So I copy the autogenerated XML filter and paste it for safe keeping in a blank Notepad. I then edit the query. If I mess it up, I simple return to Notepad, retrieve my previous query, and start over. Simple.

Looking for instances of LYNC hangs

When I was rummaging around in the Event Viewer, I noticed that several of the hangs were caused by Lync.exe. So, I thought I would create a custom query to look for those instances. To do this, I need to get into the Event Data node and look for Lync.

After I create a generic XML query by using the GUI tools, I copy the query, and turn it into a here string. Here is the basic query:

<QueryList>

  <Query Id="0" Path="Application">

    <Select Path="Application">*[System[Provider[@Name='Application Hang'] and (Level=2) and (EventID=1002)]] </Select>

  </Query>

</QueryList>

To make it a here string, I add @” and “@ around the string, and I assign it to a variable. Now I need to access EventData and the first data that is equal to Lync.exe. I add it after EventID=1002)]] by using and to bring them together. Here is the completed query.

$query = @"

<QueryList>

  <Query Id="0" Path="Application">

    <Select Path="Application">*[System[Provider[@Name='Application Hang']

    and (Level=2) and (EventID=1002)]]

    and *[EventData[Data='lync.exe']]</Select>

  </Query>

</QueryList>

"@

To run it, all I do is call the Get-WinEvent and pass it to the $query parameter as a value for –FilterXML. This is shown here:

Get-WinEvent -FilterXml $query 

The command and the results are shown in the following image:

Without using XML

Without using XML, someone may come up with a command something like the following:

Get-WinEvent -LogName application |

    where { $_.providername -eq 'application hang' -and

    $_.level -eq 2 -and

    $_.ID -eq 1002 -and

    $_.message -match 'lync.exe'}

It works, and it gets the job done. But what about the results?

Although the command seems to work pretty well, I will use Measure-Command to see how well. To do this, I add the command to a script block for Measure-Command. Here is what it looks like:

Measure-Command {Get-WinEvent -LogName application |

    where { $_.providername -eq 'application hang' -and

    $_.level -eq 2 -and

    $_.ID -eq 1002 -and

    $_.message -match 'lync.exe'} }

The results? It takes 10.16 seconds as shown here:

And now for the XML query…

$query = @"

<QueryList>

  <Query Id="0" Path="Application">

    <Select Path="Application">*[System[Provider[@Name='Application Hang']

    and (Level=2) and (EventID=1002)]]

    and *[EventData[Data='lync.exe']]</Select>

  </Query>

</QueryList>

"@

Measure-Command {Get-WinEvent -FilterXml $query }

The results take a mere 0.07 second. This is an amazing speed increase. Here is an image of the script and the output:

Although this is a great performance, and it makes me happy on my laptop, suppose I was trying to run the command against a thousand computers. That ten seconds stretches into over two and a half hours. I spent less than five minutes making the query. So five minutes to save ten seconds is not a great investment. But five minutes dev time to save over two and a half hours is a great ROI.

Spend a little time to work out the syntax for XML filters by using Get-WinEvent. This is an area where a bit of investment in learning will pay off handsomely in the future.

That is all there is to using Get-WinEvent and an XML filter to parse the event log message data. Event Log Week will continue tomorrow when I will talk about more cool stuff.

I invite you to follow me on Twitter and Facebook. If you have any questions, send email to me at scripter@microsoft.com, or post your questions on the Official Scripting Guys Forum. See you tomorrow. Until then, peace.

Ed Wilson, Microsoft Scripting Guy