SQL Server – Profiler – Part 6 – Correlating the Profiler Trace with Windows Performance Log Data


Based on popular demand from my colleagues and you, the kind reader, I am currently writing a series of posts on the SQL Server Profiler. Five parts have been published till date, and for your kind reference, here are the links to them:

  1. What is a SQL Trace? Permissions, space requirements and launching the Profiler
  2. Profiler Templates, Template Types & creating custom templates
  3. Trace execution options – Save trace to file or a table, Auto-scroll and keyboard shortcuts
  4. Review T-SQL code to identify objects no longer supported by Microsoft – Deprecation Event
  5. Replaying a trace – from a file or a table – using breakpoints during trace replay

Today, in the last part of the series, we will be looking at another important application of the SQL Server Profiler – Correlating the Profiler Trace with Windows Profiler Log Data. This is helpful when you, as an IT or database administrator suspect that SQL Server is either being held up by or is the cause of an I/O, memory or processor contention.

Windows Reliability & Performance Monitor Log Data

Windows Reliability and Performance Monitor is a Microsoft Management Console (MMC) snap-in that combines the functionality of previous stand-alone tools including Performance Logs and Alerts, Server Performance Advisor, and System Monitor. The tool of interest to us is the Performance Logs and Alerts, erstwhile known as “Perfmon”.

Because this is a post on the SQL Server Profiler, demonstrating the capture of data using the Windows Reliability and Performance Monitor is out of scope. You may refer the References section for more details on the Windows Reliability and Performance Monitor.

For this test, I have created a Performance trace of the following counters (because the goal of this exercise was just to have a demonstration, very basic counters have been chosen. Under “live” circumstances, the counter range would be different):

  • Total Disk – Reads/sec
  • Total Disk – Writes/sec
  • Total Disk – Current Queue Length
  • SQL Server Buffer Manager – Page reads/sec
  • SQL Server Buffer Manager – Page writes/sec

SQL Server Profiler Trace Data

Using the custom trace developed in earlier editions of this series, capture a SQL Server Profiler Log for the following script. Notice that the script has been designed to have a distinct set of read & write activities:

/**********************************************
           !!!! WARNING !!!!
THIS SCRIPT IS PROVIDED AS-IS AND WITHOUT
WARRANTY. THE AUTHOR AND BEYONDRELATIONAL.COM
ARE NOT RESPONSIBLE FOR ANY DAMANGE CAUSED BY
THE USE OF THIS SCRIPT.
**********************************************/
USE tempdb
GO
CREATE TABLE DefaultTableTest
( DataId INT IDENTITY(1,1),
  RandomId INT DEFAULT (RAND()*1000),
  DataName VARCHAR(10) DEFAULT 'DEFAULT'
)
GO

/******************************************
   Insert some test data into the table
- This should generate lots of writes
******************************************/
USE tempdb
GO
INSERT INTO DefaultTableTest DEFAULT VALUES
GO 20000

/******************************************
   Fetch the test data
- This should generate lots of reads!
******************************************/
USE tempdb
GO
SELECT * FROM DefaultTableTest
GO
SELECT * FROM AdventureWorks2008R2.HumanResources.Employee
GO
--Wait for some time
WAITFOR DELAY'00:00:20'
--Regenerate some activity
USE tempdb
GO
SELECT * FROM DefaultTableTest
GO
SELECT * FROM AdventureWorks2008R2.HumanResources.Employee
GO

It is important to remember that the time ranges for the Windows Performance Monitor Log and SQL Server Profiler Trace log must overlap for the Profiler to be able to correlate them.

Correlating the Profiler Trace with Windows Performance Log Data

Once the data has been collected, now is the time to correlate the Profiler trace with the Windows Performance Log data. Below are the steps that you can use to do so:

In the SQL Server Profiler, open the saved Profiler trace file image
On the SQL Server Profiler File menu, click Import Performance Data image
In the Open dialog box, select a file that contains a performance log.

In the Performance Counters Limit dialog box, select the check boxes that correspond to the System Monitor objects and counters that you want to display alongside the trace. Click OK.

image

Notice that the performance monitor graph came out to be exactly as expected

  • Lot of Page writes in the beginning
  • Very small period of disk reads and buffer page reads towards the end
  • Note that disk writes continue in an even fashion throughout – indicating disk writing by the SQL Profiler and the Performance monitor
image

Select an event in the trace events window, or navigate through several adjacent rows in the trace events window by using the arrow keys.

The vertical red bar in the System Monitor data window indicates the performance log data that is correlated with the selected trace event.

image
Click a point of interest in the System Monitor graph.

The corresponding trace row that is nearest in time is selected.

Once the graph receives the mouse click, you can also use the right & left arrow keys to navigate

image
To zoom in on a time range, press and drag the mouse pointer (as if you are selecting a section of an image) in the System Monitor graph image

NOTES:

  1. The time ranges of the Profiler & Windows Performance Log data must overlap
  2. For accurate correlation with System Monitor data, the trace must contain both StartTime and EndTime data columns
  3. Correlation of the Profiler & Windows Performance Log data is not possible for a running trace that is still active & collecting data

References:

I hope you liked reading all 6 parts of my series on the SQL Server Profiler. Do leave your feedback – I really appreciate and thank-you for taking the time out of your busy day to read my posts.

Until we meet next time,

Be courteous. Drive responsibly.

Subscribe to my posts via E-mail: Subscribe here | Read my posts via your favourite RSS reader: Click Here!

Advertisement

Let me know what you think about this post by leaving your feedback here!

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

This site uses Akismet to reduce spam. Learn how your comment data is processed.