At work I’ve been working on a website to collate various bits of reporting information about our infrastructure. I wanted one of these reports to be selected eventlog entries of our servers, split up by WSUS patch phases (i.e. one report per AD security group). The idea behind this was that we could arrive at work in the morning knowing that Phase X had patched overnight and take a look at a jQuery sortable HTML table showing any issues with servers in that phase/group. If this was quick enough, we could even execute it live against a single server via another website I’ve been working on (I’ll post about that later). I also want to say that while have a Solarwinds monitoring solution (APM) and their Windows based log forwarder application, the forwarded eventlogs are sent to a SQL database as syslog messages which simply don’t have the same level of detail as a Powershell event object. Anyway back on topic.

Two approaches sprang to mind:

• Invoke-Command by way of WinRM
• The remote capabilities of either Get-WinEvent or Get-EventLog

Rolling out WinRM is an ongoing project and so the latter it was. A read around online and Get-WinEvent was touted a quickest especially when querying remote computers so I started with that. I constructed my query to retrieve any errors or critical messages in the application eventlog since 4am which is the time of patching:

$computerName = "remoteserver"
# Create a timestamp after which to retrieve events. This should be from 4am on the current day:
$currDatetime = Get-Date
$day = $currDatetime.Day
$month = $currDatetime.Month
$year = $currDatetime.Year
$patchDateTime = New-Object -TypeName System.DateTime($year,$month,$day,04,00,00)
$appLog = Get-WinEvent -LogName "Application" -ComputerName $computerName -ErrorAction SilentlyContinue | Where-Object { ( ($_.LevelDisplayName -eq "Error" -or $_.LevelDisplayName -eq "Critical") -and ($_.TimeCreated -ge $patchDateTime) ) } | Select-Object TimeCreated,LogName,ProviderName,Id,LevelDisplayName,Message

It took forever to run. Ok not quite, but it took 11 minutes! Very slow.

“Back to basics” I thought. Let’s test the execution time of a simpler query on my local machine:

$yesterday = (get-date) - (new-timespan -day 1)
Measure-Command -Expression { Get-WinEventLog -LogName "Application" -ErrorAction SilentlyContinue | Where-Object { ($_.TimeCreated -ge $yesterday) -and ($_.LevelDisplayName -eq "Error") } }

22 seconds for 1 result (out of 104 records in the last 24 hours). Hmmm.

How about against the original server?:

Measure-Command -Expression { Get-WinEventLog -LogName "Application" -ErrorAction SilentlyContinue | Where-Object { ($_.TimeCreated -ge $yesterday) -and ($_.LevelDisplayName -eq "Error") } }

330 seconds (5.5 minutes) for 2 results (out of 128 records in the last 24 hours). Very disappointing. We have 140 servers and querying them all was not going to happen using this approach and standard sequential / synchronous processing. While it would be possible to save time by using asynchronous processing (background jobs or multiple threads) I was certain that this command should be orders of magnitude faster.

I did a little more reading and discovered the -FilterHashTable parameter of the Get-WinEvent cmdlet. This filters the objects while being retrieved on the server, rather than retrieving all the objects and then filtering as happens with Where-Object.

Get-Help Get-WinEvent -Parameter FilterHashTable

showed the key:value pairs accepted by the parameter. The user friendly “LevelDisplayName” key was not one of these, but luckily “Levels” of events (error,warning,information etc.) are also given the “Level” property which is accepted by FilterHashTable. “Error” = Level 2. If you want to know how to see this sort of information the easiest way is to double click an eventlog entry, click the “details” tab and then select XML view.

A new, equivalent query was born using this new method and executed against my local computer:

Measure-Command -Expression { Get-WinEvent -FilterHashTable @{LogName='Application'; Level=2; StartTime=$yesterday} -ErrorAction SilentlyContinue }

0.09 seconds! Some 244x faster. I stripped off the Measure-Command to find it was indeed pulling back the same single error record as previously (without -FilterHashtable). Fantastic!

Now against the remote server:

Measure-Command -Expression { Get-WinEvent -FilterHashTable @{LogName='Application'; Level=2; StartTime=$yesterday} -ErrorAction SilentlyContinue -ComputerName $remoteserver }

0.43 seconds.

So back to my original command. As we’re not allowed duplicate keys in a hash table two queries were needed:

$appErrors = Get-WinEvent -FilterHashTable @{LogName='Application'; Level=2; StartTime=$yesterday} -ErrorAction SilentlyContinue -ComputerName $remoteserver | Select-Object TimeCreated,LogName,ProviderName,Id,LevelDisplayName,Message
$appCritical = Get-WinEvent -FilterHashTable @{LogName='Application'; Level=1; StartTime=$yesterday} -ErrorAction SilentlyContinue -ComputerName $remoteserver | Select-Object TimeCreated,LogName,ProviderName,Id,LevelDisplayName,Message
# Combine and sort the arrays
$appCombined = $appErrors + $appCritical | Sort TimeCreated

1.85 seconds. Outstanding :)

I then went on my merry way about creating a fully fledged script. Ultimately it worked very well and against a batch of 20 servers took 3.89 minutes with some 18,000 records returned, although it did complain with many “There are no more endpoints available from the endpoint mapper.” error messages which I noticed were against our 2003 servers. It appears that Get-WinEvent doesn’t work against 2003 but at least from a 2008R2 server it happily works against 2008+ with -FilterHashTable. I may have to construct a different, equivalent Get-EventLog query purely for the 2003 servers.