Administrators often want to monitor the event logs and look for specific error conditions.  The most capable way to do this, of course, is to use a dedicated monitoring application such as Microsoft Operations Manager, or get down-and-dirty with the Win32 API NotifyChangeEventLog.  However, Monad can be used for simple applications.

Suppose you are looking for event ID 4226 in the System log.  The trivial way to do this is "get-eventlog System | where {$_.EventID -eq 4226}", but this has two problems:

  • This will report the same errors every time you run it, no matter how old they get, until they are cleared from the log.
  • Event logs can contain literally millions of events.  So, a simple script like this might work on your test server, but could get completely bogged down on your production servers.  If you are building software to be distributed to customers whose log configuration you do not control, this is almost certainly unacceptable.

For these reasons, you may want to be a little more clever about searching the event log.  Here is a script which searches logs incrementally, keeping track each time of the log index it reached last time and only reporting new hits.  The log position is stored in a content object, by default file "<home>\System_Position.txt".  Because this content object is only accessed using get-content and set-content, it doesn't have to be a file; it could be an item from any provider implementing IContentCmdletProvider!  The output objects are the same as get-eventlog, so no additional formatting directives are needed.

There are five script parameters:

  • -LogName is the script you want to read, by default "System".
  • -Filter is the filter which identifies the events you want.  This should be expressed as a script block which gets an EventLogEntry as "$_" and yields a boolean value.  By default this is "{$true}" which means output all entries.
  • -PositionFile is the path to the content object which keeps track of the last checked position, by default "<home>\<LogName>_position.txt".
  • -Force:  If specified, continue with the operation even if the current content object does not exist or is invalid.  All "[switch]" parameters are false by default; you can just specify "-Force" to make it true, or "-Force:$var" to set it to a shell variable value.
  • -Restart:  If specified, create a new position file and start from the beginning of the log.  You will need to use -Restart the first time to create the position file.  This is a "[switch]" parameter like -Force.

One line of this script is of particular interest:

    # This line actually generates the output
    $entry | where $Filter

If the scriptblock in $Filter evaluates to true, then the entry will be written to the script's output stream.  The scriptblock will evaluate in the same scope as the script as a whole; to achieve better isolation between the user-provided scriptblock and the main script, "where {&$Filter}" will create a new scope every time.

Also note the use of the write-debug, write-warning, and write-verbose cmdlets in the script.  Script users can set $DebugPreference, $VerbosePreference, and/or $WarningPreference to see this text when desired.

A little domain-specific information about the EventLog is required to fully understand this script.  First, we check EventLogEntry.Index to determine whether an entry has already been seen, rather than EventLogEntry.TimeGenerated or the like.  Remember that the system clock can be modified at any time (e.g. if the user determines that it is running fast), whereas the Index will reliably increment until the log is cleared.  Second, we also remember the TimeGenerated of the newest log entry in the position file.  This enables us to detect when the log has been cleared, which is important since new entries will have Index starting from 1 after the reset.

Further features could probably be added to this script, for example, a way to initialize a position file to the current position so that you don't ever have to read the entire log.

Thanks to Bruce Payette and Jim Truher for their help with the script.

Enjoy!

Jon Newman [MSFT]

 


# Eventlog monitoring script 2006/03/28 JonN
#
# Event logs can contain hundreds of thousands of items, so
# "get-eventlog System | where {<condition>}" can take excessively long
# on production systems.  Plus, the same failures will be reported
# over and over.
# This script will remember your last Index position in the log,
# and only report events which occurred since then.
# It also remembers the TimeGenerated of the oldest log entry,
# so that it can detect when the log has been cleared.
# Example:
# eventlog.msh1 -LogName System -Filter {$_.EventID -eq 4226} -PositionFile "c:\logs\syslogpos.txt"

param (
    [string]$LogName = "System",
    [ScriptBlock]$Filter = {$true},
    [string]$PositionFile = $home + "\" + $LogName + "_position.txt",
    [switch]$Force,
    [switch]$Restart
    )

write-debug "`$LogName = $LogName"
write-debug "`$Filter = '$Filter'"
write-debug "`$PositionFile = '$PositionFile'"
write-debug "`$Force = $Force"
write-debug "`$Restart = $Restart"

[int]$lastCheckedIndex = -1
[DateTime]$lastCheckedTime = [DateTime]::MaxValue

if (!$Restart)
{
    $filecontent = get-content $PositionFile -ea SilentlyContinue
    if ($null -eq $filecontent)
    {
        if (!$Force)
        {
      throw "Position file '$PositionFile' does not exist or could not be opened. Use -Force or -Restart to create a new position file."
        }
        write-verbose "Position file '$PositionFile' does not exist or could not be opened.  Rebuilding position file because -Force was specified."
    }
    else
    {
        write-debug "Position file contains '$filecontent'"
        trap {
            if ($Force)
            {
                write-warning "Content of position file '$PositionFile' is invalid.  Rebuilding position file because -Force was specified."
                $lastCheckedIndex = -1
                $lastCheckedTime = [DateTime]::MaxValue
                continue
            }
      throw "Content of position file '$PositionFile' is invalid.  Terminating operation.  Use -Force or -Restart to rebuild the position file."
        }
        # These lines will throw if the cast fails
        $lastCheckedIndex = $filecontent[0]
        $lastCheckedTime = $filecontent[1]
    }
}

write-debug "`$lastCheckedIndex = $lastCheckedIndex"
write-debug "`$lastCheckedTime = $lastCheckedTime"

# I don't simply call get-eventlog $LogName because I don't want to
# build an array with all the hundreds of thousands of event log entries.
# Instead, I make sure the EventLogEntryCollection is not unrolled.
$log = get-eventlog -List | where {$_.Log -ieq $LogName}
if ($null -eq $log)
{
    throw "Log not found: $LogName"
}

$entries = $log.Entries
if (0 -eq $entries.Count)
{
    write-debug "Log empty: $LogName"
    return
}

$oldestEntryTime = $entries[0].TimeGenerated
if ($oldestEntryTime -gt $lastCheckedTime)
{
    write-verbose "The log appears to have been cleared since it was last checked: $LogName."
    $lastCheckedIndex = -1
}

# The index can diverge from the number of entries
# when the log reaches its maximum size and is configured
# to "Overwrite entries as needed"
$newestEntryIndex = $entries[$entries.Count - 1].Index
$newestEntryTime = $entries[$entries.Count - 1].TimeGenerated

write-debug "Newest entry in log has index $newestEntryIndex"
write-debug "Newest entry in log has TimeGenerated $newestEntryTime"

# $entries.Count could be more than the maximum range "50000 .. 0"
foreach ($i in ($entries.Count - 1) .. 0)
{
    $entry = $entries[$i]
    if ($entry.Index -le $lastCheckedIndex) {
        break
    }
    # This line actually generates the output
    $entry | where $Filter
}

write-debug "Writing index $newestEntryIndex to position file '$PositionFile'"
write-debug "Writing time $newestEntryTime to position file '$PositionFile'"
$newestEntryIndex,$newestEntryTime | set-content $PositionFile