8

I would like to setup an audit trail kind of system on my database to monitor for UPDATE/INSERT statements on a specific table with very high activity. I have two options in front of me: using the SQL Server built-in Audit system or go with Extended Events.

As SQL Server Audit internally uses Extended Events, I assume there will be some kind of overhead when I use Audit instead of Extended Events directly.

Is there any way I can do some testing to analyze which system is impacting the server more? If I could know what actually happens when any XE session is created it would help me in analyzing the impact on the server.

We considered triggers and left out that option because of overhead. But that was just decided based on information from the Internet.

  • Let us continue this discussion in chat. – wBob May 26 '16 at 20:34
  • Not all events that are captured via a SQL Audit are accessible through XEvents. SQL Audit utilizes the same engine behind XEvents, but they are separate features. – Shawn Melton Jun 2 '16 at 5:19
  • Yeah.came to know about that. But when we did some kind of load testing(see below) , we observed that XE has more overhead than Audit. If audit uses XE in the background, any idea why it is causing more overhead ? – karun_r Jun 2 '16 at 5:28
3

I created a simple test rig to trial SQL Server Audit against triggers, and potentially other options. In my tests of inserting 1 million rows into a table I got 52, 67 and 159 seconds for baseline, SQL Audit and my trigger respectively:

Test Results

Now this isn't particularly scientific but does potentially offer you one way of comparing approaches. Have a look through the script, see if it can be of use to you:

USE master
GO

SET NOCOUNT ON
GO

IF EXISTS ( SELECT * FROM sys.databases WHERE name = 'testAuditDb' )
ALTER DATABASE testAuditDb SET SINGLE_USER WITH ROLLBACK IMMEDIATE
GO
IF EXISTS ( SELECT * FROM sys.databases WHERE name = 'testAuditDb' )
DROP DATABASE testAuditDb
GO


CREATE DATABASE testAuditDb
ON PRIMARY
( NAME = N'testAuditDb', FILENAME = N's:\temp\testAuditDb.mdf', SIZE = 1GB, MAXSIZE = UNLIMITED, FILEGROWTH = 128MB )
LOG ON 
( NAME = N'testAuditDb_log', FILENAME = N's:\temp\testAuditDb_log.ldf', SIZE = 100MB, MAXSIZE = 2048GB, FILEGROWTH = 128MB )
GO

ALTER DATABASE testAuditDb SET RECOVERY SIMPLE
GO



------------------------------------------------------------------------------------------------
-- Setup START
------------------------------------------------------------------------------------------------

USE testAuditDb
GO

CREATE SCHEMA auditSchema

-- Create a table
CREATE TABLE auditSchema.auditTable ( 
    rowId INT IDENTITY PRIMARY KEY, 
    someData UNIQUEIDENTIFIER DEFAULT NEWID(), 
    dateAdded DATETIME DEFAULT GETDATE(), 
    addedBy VARCHAR(30) DEFAULT SUSER_NAME(), 
    ts ROWVERSION 
)
GO


-- Setup END
------------------------------------------------------------------------------------------------



------------------------------------------------------------------------------------------------
-- Test 01 - Baseline START
-- Normal timing; no triggers or audits
------------------------------------------------------------------------------------------------


-- Add a million rows to the table and time it.
DECLARE @i INT = 0, @startTime DATETIME2, @endTime DATETIME2

SET @startTime = SYSDATETIME()

WHILE @i < 1000000
BEGIN

    INSERT INTO auditSchema.auditTable DEFAULT VALUES

    SET @i += 1
END

SET @endTime = SYSDATETIME()

SELECT DATEDIFF( second, @startTime, @endTime ) AS baseline
GO


-- Cleanup
TRUNCATE TABLE auditSchema.auditTable 
GO

-- Test 01 - Baseline END
------------------------------------------------------------------------------------------------





------------------------------------------------------------------------------------------------
-- Test 02 - SQL Audit START
-- Try SQL Audit
------------------------------------------------------------------------------------------------

-- Create server audit in master database
USE master
GO

------------------------------------------------------------------------------------------------------------------------
-- The server audit is created with a WHERE clause that limits the server audit to only the auditTable table.
------------------------------------------------------------------------------------------------------------------------
CREATE SERVER AUDIT auditTableAccess TO FILE ( FILEPATH = 'S:\SQLAudit\' ) WHERE object_name = 'auditTable';
GO
ALTER SERVER AUDIT auditTableAccess WITH ( STATE = ON );
GO

-- Create the database audit specification in the testAuditDb database 
USE testAuditDb;
GO

CREATE DATABASE AUDIT SPECIFICATION [dbAudit1]
FOR SERVER AUDIT auditTableAccess
ADD ( 
    SELECT, INSERT, UPDATE ON SCHEMA::[auditSchema]
    BY [public]
    ) WITH ( STATE = ON );
GO


-- Add a million rows to the table and time it.
DECLARE @i INT = 0, @startTime DATETIME2, @endTime DATETIME2

SET @startTime = SYSDATETIME()

WHILE @i < 1000000
BEGIN

    INSERT INTO auditSchema.auditTable DEFAULT VALUES

    SET @i += 1
END

SET @endTime = SYSDATETIME()

SELECT DATEDIFF( second, @startTime, @endTime ) AS sqlAudit
GO


-- Cleanup
TRUNCATE TABLE auditSchema.auditTable
GO
ALTER DATABASE AUDIT SPECIFICATION [dbAudit1] WITH ( STATE = Off );
DROP DATABASE AUDIT SPECIFICATION [dbAudit1]
GO

USE master
ALTER SERVER AUDIT auditTableAccess WITH ( STATE = OFF );

DROP SERVER AUDIT auditTableAccess
GO



/*
-- Inspect the audit output
IF OBJECT_ID('tempdb..#tmp') IS NOT NULL DROP TABLE #tmp

SELECT *
INTO #tmp
FROM fn_get_audit_file ( 'S:\SQLAudit\auditTableAccess_*.sqlaudit', DEFAULT, DEFAULT );
GO


SELECT statement, MIN(event_time), MAX(event_time), COUNT(*) AS records
FROM #tmp
GROUP BY statement
GO
*/

-- Test 02 - SQL Audit END
------------------------------------------------------------------------------------------------




------------------------------------------------------------------------------------------------
-- Test 03 - Triggers START
-- Trial INSERT/UPDATE trigger with log table
------------------------------------------------------------------------------------------------
USE testAuditDb
GO

CREATE TABLE dbo.auditLog
    (
    auditLogLog     INT IDENTITY PRIMARY KEY,
    schemaName      SYSNAME NOT NULL,
    tableName       SYSNAME NOT NULL,
    dateAdded       DATETIME NOT NULL DEFAULT GETDATE(),
    addedBy         SYSNAME NOT NULL DEFAULT SUSER_NAME(),
    auditXML        XML
    )
GO


-- Generic audit trigger
CREATE TRIGGER trg_dbo__triggerTest ON auditSchema.auditTable
FOR INSERT, UPDATE, DELETE

AS

BEGIN

    IF @@rowcount = 0 RETURN

    SET NOCOUNT ON

    DECLARE @action VARCHAR(10)

    IF EXISTS ( SELECT * FROM inserted )
    AND EXISTS ( SELECT * FROM deleted )
        SET @action = 'UPDATE'
    ELSE IF EXISTS ( SELECT * FROM inserted )
        SET @action = 'INSERT'
    ELSE IF EXISTS ( SELECT * FROM deleted )
        SET @action = 'DELETE'

    INSERT INTO dbo.auditLog ( schemaName, tableName, auditXML )
    SELECT OBJECT_SCHEMA_NAME( parent_id ) schemaName, OBJECT_NAME( parent_id ) tableName,
        (
        SELECT
            @action "@action",
            ( SELECT 'inserted' source, * FROM inserted FOR XML RAW, TYPE ),
            ( SELECT 'deleted' source, * FROM deleted FOR XML RAW, TYPE )
        FOR XML PATH('mergeOutput'), TYPE
        ) x
    FROM sys.triggers
    WHERE OBJECT_ID = @@procid
      AND ( EXISTS ( SELECT * FROM inserted )
         OR EXISTS ( SELECT * FROM deleted )
          )

END
GO


-- Add a million rows to the table and time it.
DECLARE @i INT = 0, @startTime DATETIME2, @endTime DATETIME2

SET @startTime = SYSDATETIME()

WHILE @i < 1000000
BEGIN

    INSERT INTO auditSchema.auditTable DEFAULT VALUES

    SET @i += 1
END

SET @endTime = SYSDATETIME()

SELECT DATEDIFF( second, @startTime, @endTime ) AS triggers
GO

-- Cleanup
TRUNCATE TABLE auditSchema.auditTable
DROP TABLE dbo.auditLog
DROP TRIGGER auditSchema.trg_dbo__triggerTest
GO

-- Test 03 - Triggers END
------------------------------------------------------------------------------------------------

Whilst the trigger option didn't do very well here, my trigger code could be simplified depending on what you want to capture and it does allow you access to the old and new values in a fairly usable format which SQL Audit does not. I have used this technique for a lower-activity config table and it works quite well. Depending on what you want to capture you could also consider Change Data Capture.

Let me know how you get on with your trials. Good luck.

3

One benefit of the Audit that comes to mind is that it will automatically record who turns it on and off, XE won't do that out of the box (though you might find an event that tracks XE stop/start). You may also find that the two capture different data, depending on exactly what you want.

Regarding doing some testing, you would need to have a database backup, capture a trace of the application under load, and then restore the copy while doing a replay / replay with audit / replace with XE and comparing performance data.

Which performance data? It's up to you. For some ideas - Linchi Shea did a comparison between Audit and Trace by focusing on Transactions/sec, while Kehayias did a comparison between Trace and XE by focusing on batches/sec and overall replay runtime.

I'd encourage you to read both and their comments because you should know that no matter what you do it will be open to interpretation. It's difficult to get an apples for apples comparison. Also, a trace/replay can fail to simulate load properly - for example when your application is doing lots of bulk loads from disk files that no longer exist.

But the important thing is that you try at least one thing, so you can justify your decisions, and also blog about it for the rest of us.

  • When you say that audit will auto capture the audit ON/OFF events, are you talking about AUSC action types in the audit trail ? Also, for ideal performance testing , I guess I should consider the current bottlenecks of the application and see if either audit or XE are making them any worse. – karun_r May 26 '16 at 7:45

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.