Data Mine the Windows Event Log by Using PowerShell and XML


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:

Image of menu

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:

Image of menu

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:

Image of menu

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:

Image of command output

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:

Image of command output

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:

Image of command 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 

Comments (14)

  1. Excellent article. Thank you.

  2. jrv says:

    @Ed – here is your query as XPath. It is somewhat more compact.

    $xpath="*[System[Provider/@Name=’Application Hang’]] and *[System/Level=2] and *[System/EventID=1002]"
    Get-WinEvent -LogName Application -FilterXPath $xpath

    One thing that all of you who may experiment with this. "XML", "XPath" and "XQuery" are case sensitive everywhere. Terms like and/or are also case sensitive and must be in all lowercase.

  3. jrv says:

    Excellent blog on XML queries. We hope you will also address XPath queries as they can be much easier to build and accomplish the same goals.

    EXAMPLE:

    $xpath=@’
    *[System[Provider/@Name="Microsoft-Windows-Kernel-Power"]]
    and
    *[System/EventID=131]
    ‘@
    Get-WinEvent -LogName system -FilterXPath $xpath

  4. Thanks Ed… did you end up finding out the cause of Lync hanging?

  5. Ed Wilson says:

    I think it is a problem with my ISP. I have LOTS of weird problems in my event logs, all of them trace back to Internet connectivity issues. I applied all of the updates, and still get intermittent hangs.

  6. Derek Blackburn says:

    Thanks this was really helpful.

  7. JarvisDavis says:

    How come the following query doesn’t work?

    $query=@"

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

    it says cannot convert value "…." to type "System.Xml.XmlDocument". Error: "Unexpected end tag…

  8. JarvisDavis says:

    Never mind my previous comment, figured it out.

  9. JarvisDavis says:

    How can we get a detailed output?

  10. H Eng says:

    This is great, but how about the search keys that can be used? I tried UserId=’S-1-5-21-xxxxxxxxx-xxxxxxxxxx-xxxxxxxxx-xxxx’ and it never worked for me. How to search by UserId?

  11. jim says:

    Can this work with Event Logs on Windows 2003?

  12. Kelly Dyjur says:

    Hi Ed, great article; why is the XML search faster by magnitudes? There is really no comparison between the two search times.

  13. roger says:

    The speed of the XML filtering is impressive. I really want to get over the hump of learning to apply this better. Several specific Eventlog items I need to filter on include a percent sign “%” or double at the beginning of the field, usually this is in both the friendly and XML view. I have not been able to find an escape for the % sign inside the xml query. References to an operator “Ends-With” suggest it doesn’t work (and haven’t been able to prove it wrong), but would be nifty if it did. A number of critical fields show up with a leading %, guids, properties, access list, seems there must be a way around this that I have just not discovered. If it is obvious and stupid, so much the better. Help?

Skip to main content