Five parts have been published till date, and for your reference, here are the links to them:

1. What is a SQL Trace?
2. Profiler Templates, Template Types and Creating Customized Templates
3. Trace execution options
4. Identify objects no longer supported by Microsoft - Deprecation Event
5. Replaying a trace

Today, 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

On the SQL Server Profiler File menu, click Import Performance Data

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.

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

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.

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

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

NOTES:

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

References:

• Windows Reliability & Performance Monitor
• Correlate a trace with Windows Performance Log Data
• All uses of the Profiler
• Profiler keyboard shortcuts