Performance Impact of SQL Server Profiler

The general best practice is only capture the events and columns you need when using SQL Server Profiler.  But how much impact does it have?  Well the answer always been for me IT DEPENDS!

But really how much impact does it back?  So I decided to do some testing.  I will be using the code below for each test case scenario.

USE TempDB
GO

SET NOCOUNT ON
GO

SELECT GETDATE()
GO

CREATE TABLE T1 (Col1 INT, Col2 INT, Col3 INT)
GO

DECLARE @Cntr INT

SET @Cntr = 0

WHILE (@Cntr < 100000)
BEGIN
SET @Cntr = @Cntr + 1
INSERT INTO T1 VALUES (@Cntr, @Cntr*10, @Cntr*100)
END
GO

DROP TABLE T1
GO

SELECT GETDATE()
GO

Note: I know there are better way to do large insert, but for this test, this way works pretty nice :).

I am simply creating a table throwing 100,000 rows in it.  And taking the start time and end time.  So I can calculate the total time it takes to complete the operation.  In my control test, with no SQL Server Profile, it took 2416ms to complete this insert.

Now I set up a SQL Server Profile with following Events (with all columns):

Errors and Warnings

• ErrorLog
• EventLog
• Exception

Security Audit

• Audit Login
• Audit Logout

Stored Procedures

• RPC: Completed
• RPC: Starting
• SP: StmtCompleted
• SP: StmtStarting

TSQL

• SQL: BatchCompleted
• SQL: BatchStarting
• SQL: StmtCompleted
• SQL: StmtStarting

Lets run again and see what happens…

Waiting ….

Waiting …

I had time to go get some some coffee and snacks while it was running, when I came back it had finished.  It took 165106ms that is 68x worse.  WOW SQL Profile is evil!

Well lets not through SQL Server Profiler out on the chopping block just yet, maybe some events are more expensive?  So let me take out all of the Security and Error events, since I really don’t care about them.

And …

It executed in 166530ms, huh slightly worse.  Okay that is just weird.  Lets chop that up to my crappy laptop.  But can say those events didn’t make much dent, because they were not capturing much to begin with.  Will now what can I do?  I want to use Profiler to capture what is running, but but is just too painful to wait this long.  How about we get rid of some of the columns we don’t need?

So I have eliminated more than half of the columns and its running tick tock tick tock …

Nope it didn’t finish while I typed that sentence as I hoped… hmmm … tick tock tick tock… waiting I do…

IT FINISHED!  It finished in 56550ms, wow that is 1/3 the time it took when I captured all the columns.  But thats still 23x worse than my control?  Hmm well I don’t really need Starting events because nothing is failing.  So I’ll only captured completed.  Lets see if that helps it?

Well it helped, it finished in 40086ms.  Slightly better, but still worse then control, about 16x worse.  Improving slowly … alright lets remove RPC events (since this is all batch work).  As we seen before I don’t expect much improvement.  But what they hey… that’s why do we do testing right?

36303ms!!! Improvement why, what is going on?  Well it turns out that my SQL Server has some back ground processes running (Ooops!) that were making RPC calls, so it did hurt the performance a little. So now this is 15x worse.

I am only capturing SQL: BatchCompleted and SQL: StmtCompleted, with select number of columns.  I can possibly eliminate some more columns, but over all at this point it might not be worth it.  So the end lesson is?

SQL Server Profiler IS going to have performance impact on your server, you can minimize the impact but cannot eliminate it.

Results Summary

• Control Test, No Profiler: 2416ms (2 Seconds 416ms)
• Run #1, All Events & All Columns: 165106ms (2 Minute 45 Seconds 106ms)
• Run #2, Only RPC/TSQL Events & All Columns: 166530ms (2 Min 46 Seconds 530ms)
• Run #3, RPC/TSQL & Select Columns: 56550ms (56 Seconds 550ms)
• Run #4, Only Completed Events & Select Columns: 40086ms (50 Seconds 86ms)
• Run #5, Only TSQL & Selected Columns: 36303ms (36 Seconds 303ms)

Lessons Learned

SQL Profiler is a very important tool to find out what is happening.  But you need to understand what you need, do not capture every event and column.  You cannot eliminate the performance impact, but it is lesser of two evils.  Either know what is going on, or don’t know and live with performance problems. Yes we can use Dynamic Management Objects, but the tool is still important.

Next week I will do same test but using SQL Server Service Side Trace and follow it up with Extended Events.  After which I’ll compare all three 🙂