Sunday, September 13, 2009

Getting the Exchange Auditing event logs programmatically

With the release of Exchange 2007 SP2 some great new auditing options are now possible to let you see how and when rights are being used within your exchange environment. More importantly in a serious situation you could use these features to provide some forensic auditing of what was being accessed in your exchange store when some suspicious activity may have happened. The first place to start if your looking at auditing in Exchange 2007 SP2 is to read the very detailed white paper that has been published http://technet.microsoft.com/en-us/library/ee331009.aspx .

In this post I'm going to look at the options for reading the new Exchange Auditing event logs where folder access information is written. The Exchange Auditing logs themselves if your using Windows 2008 use the new evtx event log framework and are stored under the Application and Services Logs group

With the new .net 3.5 System.Diagnostics.Eventing.Reader class now allows you to easily parse back the information store in the event log. But before looking at this lets look at a more convention approach using Get-Eventlog can be used on both windows 2003 and 2008. Using and then you can do the text from the event log message which you can then parse out. To do a conventional parse you can split it by the Newline character and then split by semicollumn. eg

if($_.Timewritten -gt [System.DateTime]::Now.addhours(-24)){
$arry = $_.Message.ToString().Split("`n")
$mbMailbox = ""
$folderName = ""
$AccessingUser = ""
$processname = ""
$machinename = ""
$ApplicationId = ""
$Address = ""
foreach($line in $arry){
if ($line -match "Mailbox:"){
$laLineArray = $line.Split(":")
if ($laLineArray[1] -match "" -eq $false){
$mbMailbox = $laLineArray[1].Substring(1,($laLineArray[1].length-3))
}
}
if ($line -match "Display Name:"){
$laLineArray = $line.Split(":")
$folderName = $laLineArray[1].Substring(1,($laLineArray[1].length-2))
}
if ($line -match "Accessing User:"){
$laLineArray = $line.Split(":")
$AccessingUser = $laLineArray[1].Substring(1,($laLineArray[1].length-2))
}
if ($line -match "Process Name:"){
$laLineArray = $line.Split(":")
$processname = $laLineArray[1].Substring(1,($laLineArray[1].length-2))
}
if ($line -match "Machine Name:"){
$laLineArray = $line.Split(":")
$machinename = $laLineArray[1].Substring(1,($laLineArray[1].length-2))
}
if ($line -match "Application Id:"){
$laLineArray = $line.Split(":")
$ApplicationId = $laLineArray[1].Substring(1,($laLineArray[1].length-2))
}
if ($line -match "Address:"){
$laLineArray = $line.Split(":")
$Address = $laLineArray[1].Substring(1,($laLineArray[1].length-2))
}
}
}

Its a little messy like any string parse but it does the job, But whats more interesting is if you have Vista and or Windows 2008 you can start using the new eventing classes. Powershell V2 introduces the Get-WinEvent cmdlet which is a nice wrapper around these classes but as V2 isn't out yet and the underlying classes are pretty simple to use anyway i prefer the more direct method. One of the advantages of using thesse new classes is that you can do away with having to parse text out of the message fields as this information is already stored in a structure format you can access using the Eventing.Reader.EventLogRecord properties collection the order or parameters are documented in the Whitepaper i mentioned earlier.

One of the challenges of using the Eventing.Reader class is that you need to work out what the correct XPATH query will be for the data you want to retrieve from the event logs. XPath for those uninitiated is a standard used for querying XML data the event logs only supports Version 1 of XPath. This limitation affects you when you want to query for dattime within a certain timeframe which is something in the real world you generally do a lot. With Version 1 of Xpath you can only do numeric comparisons so when creating a restriction around a timespan one method you can to use the timediff function which gives you the differance between the Time of the log entry and the current time in milliseconds. So mathamatically with a little code you can query a TimeSpan using TimeSpan in Powershell.

So to put this all together into a script that will allow you to query the Exchange Auditing EventLog for events of type 10100 and where the event relates to one user accessing another users mailbox (you need to check if mailboxExchangeLegacyDN is set). This script uses a custom object to store the result and then exports the result to a csv file.

The following three varibles need to be set first before you run the code the first in the servername of the server to query the log. The next two varbile set the time From (Lastest) to the To (earliest) entry you want to retrieve.

$ServerName = "servername"
$DateFrom = [System.DateTime]::Now.addDays(-2)
$DateTo = [System.DateTime]::Now.addDays(-3)

I've put a download of this script here the script looks like

[System.Reflection.Assembly]::LoadWithPartialName("System.Core")

$ServerName = "servername"
$DateFrom = [System.DateTime]::Now.addDays(-2)
$DateTo = [System.DateTime]::Now.addDays(-3)
$DateFromTS = New-TimeSpan -Start $DateFrom -End ([System.DateTime]::Now)
$DateToTS = New-TimeSpan -Start $DateTo -End ([System.DateTime]::Now)
$eacombCollection = @()

$elLogQuery = "<QueryList><Query Id=`"0`" Path=`"Security`"><Select Path=`"Exchange Auditing`">*[System[(EventID=10100) and TimeCreated[timediff(@SystemTime) <=" + $DateToTS.TotalMilliseconds +"] and TimeCreated[timediff(@SystemTime) >= " + $DateFromTS.TotalMilliseconds +"]]]</Select></Query></QueryList>"
$eqEventLogQuery = new-object System.Diagnostics.Eventing.Reader.EventLogQuery("Exchange Auditing", [System.Diagnostics.Eventing.Reader.PathType]::LogName, $elLogQuery);
$eqEventLogQuery.Session = new-object System.Diagnostics.Eventing.Reader.EventLogSession($ServerName);
$lrEventLogReader = new-object System.Diagnostics.Eventing.Reader.EventLogReader($eqEventLogQuery)

for($eventInstance = $lrEventLogReader.ReadEvent();$eventInstance -ne $null; $eventInstance = $lrEventLogReader.ReadEvent()){
[System.Diagnostics.Eventing.Reader.EventLogRecord]$erEventRecord = [System.Diagnostics.Eventing.Reader.EventLogRecord]$eventInstance
if($erEventRecord.Properties[5].Value -match "<NULL>" -eq $false){
$exAuditObject = "" | select RecordID,TimeCreated,FolderPath,FolderName,Mailbox,AccessingUser,
MailboxLegacyExchangeDN,AccessingUserLegacyExchangeDN,MachineName,Address,
ProcessName,ApplicationId
$exAuditObject.RecordID = $erEventRecord.RecordID
$exAuditObject.TimeCreated = $erEventRecord.TimeCreated
$exAuditObject.FolderPath = $erEventRecord.Properties[0].Value.ToString()
$exAuditObject.FolderName = $erEventRecord.Properties[1].Value.ToString()
$exAuditObject.Mailbox = $erEventRecord.Properties[2].Value.ToString()
$exAuditObject.AccessingUser = $erEventRecord.Properties[3].Value.ToString()
$exAuditObject.AccessingUserLegacyExchangeDN = $erEventRecord.Properties[4].Value.ToString()
$exAuditObject.MailboxLegacyExchangeDN = $erEventRecord.Properties[5].Value.ToString()
$exAuditObject.MachineName = $erEventRecord.Properties[8].Value.ToString()
$exAuditObject.Address = $erEventRecord.Properties[9].Value.ToString()
$exAuditObject.ProcessName = $erEventRecord.Properties[10].Value.ToString()
$exAuditObject.ApplicationId = $erEventRecord.Properties[12].Value.ToString()
$eacombCollection +=$exAuditObject
}
}

$eacombCollection | export-csv –encoding "unicode" -noTypeInformation "c:\temp\exauditOutput.csv"

2 comments:

Rob said...

Nice. I was working with much the same when we discovered there's a bug in that auditing. If you turn it on, it interferes with being able to send an email item as an attachemnt, and may corrupt appointments that have item attachments.

Anonymous said...

Hi, This script is fantastic. I am desperately searching for a way to use this against an "archived" exchange log. Can you provide any help?

I am an IT admin and I have some one in our group who we KNOW is opening our mailboxes and others, but he has turned off the auditing. I can't turn it on due to "office politics" as he has convinced the interim manager that auditing causes issues on the server for performance.
I want to now try to find out how to even determine if he is granting himself full rights to the mailbox, if that were to be logged in the security log or in the domain controller logs that would be perfect. Is that possible?