Transforming Event Log Data


Several months ago I described a solution for Delegated SQL Server Administration with Powershell. In the solution, the SqlProxy module audits all security administration activity to a custom Windows Event log. In this blog post, I’ll described a process to transform and incrementally load the audit data into a SQL Server table for reporting purposes.

Writing to the Event Log

First a quick review of how  SqlProxy module writes messages to the event log. This is important because as we’ll see in a moment, how the message is constructed helps in extracting Event log data. In the SqlProxy module I use a standard template in each function for logging messages to the Event log:

$PSUserName = $PSSenderInfo.UserInfo.Identity.Name
$logmessage =  "PSUserName=$PSUserName" + $($psBoundParameters.GetEnumerator() | %{"`n$($_.Key)=$($_.Value)"})
write-sqlproxylog -eventID $eventID."$($" -message $logmessage

The message is constructed using several built-in variables written as key/value pairs.

  1. The $PSSenderInfo variable is available inside of remote session and returns information about the user who started the PSSession. Since I’m using runas credentials I’ll grab the name of the person who is connected.
  2. $psBoundParameters contains a hashtable of the parameters and their values for the current function.
  3. This code may look a little odd, $eventID.”$($”. I created hashtable called $eventid in the SqlProxy module to translate a function name from a an EventId. Since $ returns the function name I’ll use this as the hashtable key as shown below:
$EventID = @{

The write-sqlproxlog function is just a wrapper around write-eventlog as follows:


function Write-SqlProxyLog
    [Parameter(Position=0, Mandatory=$true)] $EventID,
    [Parameter(Position=1, Mandatory=$true)] $Message,
    [Parameter(Position=2, Mandatory=$false)] $EntryType='SuccessAudit'
    write-eventlog -logname SqlProxy -source SqlProxy -eventID $eventID -message $message -EntryType $EntryType
} #Write-SqlProxyLog

A typical event log entry will look like this:


Extracting Data from the Eventlog

In order to load the Eventlog data into a SQL Server table I created a module called SqlTools which is collection of functions I use frequently for querying and loading data. I’ve posted the module here.

The initial load script as shown below makes use of SqlTools module:

import-module SqlTools
$ComputerName = 'Z001'
$ServerInstance = 'Z002\sql1'
$Database = 'SqlProxy'
$dt = Get-EventLog -LogName SqlProxy -ComputerName $ComputerName -EntryType 'SuccessAudit' | % { $ht = ($_.Message -replace "\\","/") |
    ConvertFrom-StringData; $xml = new-object psobject -Property $ht | ConvertTo-Xml -NoTypeInformation -As String;
    new-object psobject -Property @{'Index' = $_.Index; 'TimeGenerated'=$_.TimeGenerated;
    'EventId'=$_.EventId; 'MessageXml'=$xml} } | Out-DataTable
Add-SqlTable -ServerInstance $ServerInstance -Database $Database -TableName 'SqlProxyLog' -DataTable $dt -AsScript | clip

At this point I’ll paste the T-SQL script into SSMS, modify column data types, null/not null, add primary key and finally create the table:


CREATE TABLE [dbo].[SqlProxyLog](
	[EventId] [int] NOT NULL,
	[TimeGenerated] [datetime] NOT NULL,
	[MessageXml] [xml] NOT NULL,
	[Index] [int] NOT NULL,
	[TimeGenerated] ASC,
	[Index] ASC

Then I’ll return to Powershell to execute the write-datatable function:

Write-DataTable -ServerInstance $ServerInstance -Database $Database -TableName 'SqlProxyLog' -Data $dt

In order to incrementally load only new events, I’ll modify the get-sqlproxylog.ps1 to first grab the max timegenerated or 1900-01-01 if its null and then use value for the -After param of the Get-Eventlog cmdlet:

import-module SqlTools
$ComputerName = 'Z001'
$ServerInstance = 'Z002\sql1'
$Database = 'SqlProxy'
$query = "SELECT ISNULL(MAX(TimeGenerated),'1900-01-01') AS TimeGenerated FROM dbo.SqlProxyLog"
$maxDtm = invoke-sqlcmd2 -ServerInstance $ServerInstance -Database $Database -Query $query | select -ExpandProperty TimeGenerated
$dt = Get-EventLog -LogName SqlProxy -ComputerName $ComputerName -EntryType 'SuccessAudit' -After $maxDtm | % { $ht = ($_.Message -replace "\\","/") |
    ConvertFrom-StringData; $xml = new-object psobject -Property $ht | ConvertTo-Xml -NoTypeInformation -As String;
    new-object psobject -Property @{'Index' = $_.Index; 'TimeGenerated'=$_.TimeGenerated;
    'EventId'=$_.EventId; 'MessageXml'=$xml} } | Out-DataTable
if ($dt) {
    Write-DataTable -ServerInstance $ServerInstance -Database $Database -TableName 'SqlProxyLog' -Data $dt

Some interesting points about this script:

  • Since the message data is stored as key/value pairs, the built-in ConvertFrom-StringData cmdlet is used to create the hashtable $ht
  • The hashtable is then used to create a psobject
  • The psobject is converted into XML using ConverTo-Xml.

One minor issue I ran into is with unenclosed backslashes. If backslashes are enclosed in quotes its fine, if not it causes an error with ConvertFrom-StringData, so I replace them with forward slashes.

Data Is Loaded, Now What?

After I’ve loaded the data I’ll use XQuery to shred the message XML column into a relational data set. I created a function and view in SQL Server for this purpose:

CREATE FUNCTION [dbo].[ufn_GetEventMessage] (@MessageXml XML)
	 ChangeOrder VARCHAR(128) NULL
	,dbname  VARCHAR(128) NULL
	,PSUserName   VARCHAR(255) NULL
	,name   VARCHAR(128) NULL
	,rolename   VARCHAR(128) NULL
	,[Description]   VARCHAR(128) NULL
	,sqlserver   VARCHAR(128) NULL
	,loginame   VARCHAR(128) NULL
	,[login]   VARCHAR(128) NULL
	,DefaultDatabase VARCHAR(128) NULL
	INSERT @Message (ChangeOrder,dbname,PSUserName,name,rolename,Description,sqlserver,loginame,[login],DefaultDatabase)
	 Objects.Object.query('Property[@Name="ChangeOrder"]').value('.', 'varchar(128)') AS ChangeOrder
	,Objects.Object.query('Property[@Name="dbname"]').value('.', 'varchar(128)') AS dbname
	,Objects.Object.query('Property[@Name="PSUserName"]').value('.', 'varchar(128)') AS PSUserName
	,Objects.Object.query('Property[@Name="name"]').value('.', 'varchar(128)') AS name
	,Objects.Object.query('Property[@Name="rolename"]').value('.', 'varchar(128)') AS rolename
	,Objects.Object.query('Property[@Name="Description"]').value('.', 'varchar(128)') AS [Description]
	,Objects.Object.query('Property[@Name="sqlserver"]').value('.', 'varchar(128)') AS sqlserver
	,Objects.Object.query('Property[@Name="loginame"]').value('.', 'varchar(128)') AS loginame
	,Objects.Object.query('Property[@Name="login"]').value('.', 'varchar(128)') AS [login]
	,Objects.Object.query('Property[@Name="DefaultDatabase"]').value('.', 'varchar(128)') AS DefaultDatabase
	FROM @MessageXml.nodes('/Objects/Object') AS Objects(Object)
CREATE VIEW [dbo].[vw_SqlProxyLog]
SELECT l.*, m.*
FROM dbo.SqlProxyLog l
CROSS APPLY dbo.ufn_GetEventMessage(l.MessageXml) m

The function requires I define all the possible attributes as columns. Here’s an example of parsing a typical message:

SET @MessageXml =
'<Objects><Object><Property Name="DefaultDatabase">master</Property>
<Property Name="PasswordPolicyEnforced">False</Property>
<Property Name="Description" />
<Property Name="sqlserver">[Z002/SQL1]</Property>
<Property Name="password">System.Security.SecureString</Property>
<Property Name="name">test3</Property>
<Property Name="PasswordExpirationEnabled">False</Property>
<Property Name="ChangeOrder">1234</Property>
<Property Name="logintype">SqlLogin</Property>
<Property Name="PSUserName">Z002/u00</Property>
SELECT * FROM dbo.ufn_GetEventMessage(@MessageXMl)
ChangeOrder PSUserName name sqlserver DefaultDatabase
1234 Z002/u00 test3 [Z002/SQL1] master

Finally I’ll add reference table for the SqlProxyEventType:

CREATE TABLE [dbo].[SqlProxyEventType](
	[EventName] [varchar](50) NOT NULL,
	[EventId] [smallint] NOT NULL,
	[EventId] ASC
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Add-SqlDatabaseRoleMember', 0)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Add-SqlLogin', 1)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Add-SqlServerRoleMember', 2)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Add-SqlUser', 3)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Remove-SqlDatabaseRoleMember', 4)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Remove-SqlLogin', 5)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Remove-SqlServerRoleMember', 6)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Remove-SqlUser', 7)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Rename-SqlLogin', 8)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Set-SqlLogin', 9)
INSERT [dbo].[SqlProxyEventType] ([EventName], [EventId]) VALUES (N'Set-SqlLoginDefaultDatabase', 10)

The last thing I’ll do is setup a schedule SQL Agent job to run the get-sqlproxylog.ps1 script:

–Setup SQL Job with CmdExec Job Step:

–C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe -NoProfile -Command c:\scripts\get-sqlproxylog.ps1


This post demonstrated extracting information from a specially crafted message in an event log and loading the data into a SQL Server table. Its kind of interesting to think about how easy it is to transform data from one thing to the next using Powershell. In this case the data was converted six times:

  1. To an Event log message data stored as key/value pairs using Write-Eventlog/Get-Eventlog
  2. To a hashtable using ConvertFrom-StringData
  3. To a psobject using New-Object -property hashtable
  4. To a DataTable using Out-DataTable
  5. Into a SQL Server table using Write-DataTable
  6. Out of a SQL Server table XML column to relational data set using XQuery

That said, next time I should probably just write the damn thing directly to a database to begin with.