Tag Archives: data

Custom event log queries

I really like the newer event log model on Windows 2008 family, and the flexibility of the XML events and the queries that makes possible.

Recently, I started noticing a quiet failure of a scheduled task. The Task Scheduler thinks that the task completed successfully, though the executable called by the task action returned an error code of 3:

Task Scheduler successfully completed task “\ShareVol_Sync” , instance “{92ac3257-f52d-47eb-9a3a-ce02c5196bbd}” , action “diskshadow.exe” with return code 3.

I wanted to see how long this have been going on, so I switched from the Task Scheduler console to Eventlog Viewer, and navigated to the Operational log under “Applications and Services Logs”- Microsoft – Windows – TaskScheduler.

I started by using the using the Filter Current log dialog to select events with Event ID 201, but this included all “Action completed” events for all tasks. So I looked at the XML view for one of the events for the task I was researching. The event includes a data value named “ActionName” with the value “diskshadow.exe” that should allow me to find all the relevant events.

eventvwr-evt-xml

Next, I needed to refine my filter to look for this value in the events. I opened the Filter Current log dialog again, and switched to the XML tab, then checked the Edit query manually option. You get a scary warning about not being able to use the GUI again, but that only applies to the current filter. Be bold: click OK.

Next, I edited the query, following examples from this excellent Ask the Directory Services Team blog post. The query is junk the between the select tags. Originally, the query was simply:

*[System[(EventID=201)]]

To that, I added the following:

and
*[EventData[Data[@Name='ActionName'] and (Data=’diskshadow.exe’)]]

So that the whole query looks like this:

<QueryList>
  <Query Id="0" Path="Microsoft-Windows-TaskScheduler/Operational">
    <Select Path="Microsoft-Windows-TaskScheduler/Operational">
      *[System[(EventID=201)]]
       and
      *[EventData[Data[@Name='ActionName'] and (Data='diskshadow.exe')]]
    </Select>
  </Query>
</QueryList>

Now event viewer shows me only the “Action Completed” events for the diskshadow.exe command, and I can see exactly when the behavior changed.

Note that you can save use the query XML with PowerShell’s Get-WinEvent commandlet’s -filterXML parameter [See an example]. You can also use the Save Filter to Custom View option to make this view persistent.

I routinely review Windows’ Event logs during diagnostics and troubleshooting. I find the ability to query those logs for specific data is an indispensable technique. No more dumping to CSV and running findstr! I hope you find it helpful, too.

Event data mining with PowerShell

On Server 2008 and 2008 R2, if your Domain Controllers aren’t configured to require LDAP signing and disallow simple LDAP binds in plaintext, Active Directory Domain Services logs a warning event on startup, and summary events every 24 hours.

A couple weeks ago, I followed the recommendation to enable logging of unsigned and plaintext LDAP authentication requests. Setting the LDAP Interface Events value to 2 generates a Directory Services event 2889 for each connection.

Now I want to do some analysis of the collected events. The event structure puts the important details, namely the client name and IP address, in the big description text field. It looks like this:

Log Name: Directory Service
Source: Microsoft-Windows-ActiveDirectory_DomainService
Date: 11/3/2010 11:46:38 AM
Event ID: 2889
Task Category: LDAP Interface
Level: Information
Keywords: Classic
User: ANONYMOUS LOGON
Computer: CDC01.campus.ad.uvm.edu
Description:
The following client performed a SASL (Negotiate/Kerberos/NTLM/Digest) LDAP bind without requesting signing (integrity verification), or performed a simple bind over a cleartext (non-SSL/TLS-encrypted) LDAP connection.

Client IP address:
132.198.124.202:53298
Identity the client attempted to authenticate as:
CAMPUS\myhost0256BB4$

Previously, I’ve exported the logs to CSV format, then used Excel and some text-mangling functions to pull out the important details. But I noted that the two important values were nicely separated in the XML representation of the event:

Event Xml: 
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event"> 
  <System> 
    <Provider Name="Microsoft-Windows-ActiveDirectory_DomainService" Guid="{0e8478c5-3605-4e8c-8497-1e730c959516}" EventSourceName="NTDS LDAP" /> 
    <EventID Qualifiers="16384">2889</EventID>
    <Version>0</Version> 
    <Level>4</Level> 
    <Task>16</Task> 
    <Opcode>0</Opcode> 
    <Keywords>0x8080000000000000</Keywords> 
    <TimeCreated SystemTime="2010-11-03T15:46:38.219250600Z" /> 
    <EventRecordID>122013</EventRecordID> 
    <Correlation /> 
    <Execution ProcessID="512" ThreadID="3396" /> 
    <Channel>Directory Service</Channel> 
    <Computer>CDC01.campus.ad.uvm.edu</Computer> 
    <Security UserID="S-1-5-7" /> 
  </System> 
  <EventData> 
    <Data>132.198.124.202:53298</Data> 
    <Data>CAMPUS\myhost0256BB4$</Data> 
  </EventData> 
</Event>

Continue reading