How To: Use SQL Profiler

How To: Use SQL Profiler

Language Filter

Prescriptive Architecture

Improving .NET Application Performance and Scalability

J.D. Meier, Srinath Vasireddy, Ashish Babbar, and Alex Mackman
Microsoft Corporation

May 2004

Related Links

Home Page for Improving .NET Application Performance and Scalability

Chapter 14, Improving SQL Server Performance

Checklist: SQL Server Performance

Send feedback to Scale@microsoft.com

patterns & practices Library

Summary: This How To describes how to use SQL Profiler to analyze long-running queries and stored procedures. SQL Profiler traces can capture a wide variety of trace data that can be analyzed interactively, or saved for offline analysis. This How To outlines both interactive and offline analysis of trace data.

Applies To
Microsoft® SQL Server™ 2000

Overview
What You Must Know
Default Templates
Isolating a Long-Running Query with SQL Profiler
Tracking Heavily Used Stored Procedures
Additional Resources

Overview

You can use the SQL Profiler tool to debug, troubleshoot, monitor, and measure your application's SQL statements and stored procedures. SQL Profiler captures activity occurring in SQL Server, driven by requests from your client application.

The tool enables you to select precisely which events you want to monitor. For example, you might want to see when stored procedures are called, when they complete, how long they take to execute, how many logical reads occur during execution, and so on. You can also filter the trace, which is particularly useful when your database is under heavy load and a large amount of trace information is generated. SQL Profiler provides a set of templates with predefined event selection criteria. The templates are designed to capture commonly required events. You can modify and extend the templates or create your own. Trace data can be displayed interactively, or it can be captured directly to a trace file or database table.

What You Must Know

When you begin profiling, the following guidelines will help you use the tool most effectively:

Filter the captured information. In a high-traffic database, filtering enables you to capture only the required information. Consider using one of the predefined filters to:
- Filter by ApplicationName to trace data specific to one application.
- Filter by DatabaseName specify to your application if the server is hosting several databases.
- Filter by Duration to measure query performance.
- Filter by a specific object in ObjectName, and by a specific user in LoginName.
Consider saving trace information to a file. Instead of watching the trace information on-screen, you can capture the results to a file. This technique is useful for offline analysis. You can also use captured trace information as input to the SQL Server Index Tuning Wizard or insert it into a SQL Server table.
Note Sending trace data directly to a SQL Server table can incur performance overhead. It is often better to trace to a file and then import the data to a table later.

To save trace output to a file from the trace output window, click Save As on the File menu, click Trace File, and then specify a file location and a name. Trace files are given the .trc extension.
To capture output directly to a file, specify the file name details on the General tab of the Trace Properties dialog box. You should also set the maximum file size to prevent the file from growing indefinitely. Then when the file reaches the maximum size, a new file will be created.
Consider saving data to a file before sending it to a database table. The interception mechanism for capturing information can itself slow the application, depending on the volume of data captured and the number of client requests. Capturing profiler data to a database table is relatively slow compared to saving to a file. If you need to save data to database table, consider saving the data to a file first and then importing it to a database table. Doing so reduces the trace overhead and improves trace performance.
The following statement creates a table named 1108 in the current database and imports the trace information from MyTrace.trc into that table.
SELECT * INTO trace1108 FROM ::fn_trace_gettable('C:\MyTrace.trc', default)

Default Templates

SQL Server provides eight predefined templates to track events for a set of common tasks. These templates are described in Table 1 together with typical usage scenarios.

Table 1: Default Templates

Template name	Description	Usage scenario
SQLProfilerSP_Counts	Contains events to track how often stored procedures are executed.	Use to identify the most commonly used stored procedure, so that you can fine-tune it.
SQLProfilerStandard	Captures an extensive range of events and data.	Use as a start point or for general monitoring purposes.
SQLProfilerTSQL	Captures events that relate to Transact SQL (T-SQL).	Use to intercept and verify SQL statements for debugging purposes.
SQLProfilerTSQL_Duration	Events for measuring the execution cost (duration in milliseconds) of T-SQL queries and stored procedures.	Use to track down long - running queries.
SQLProfilerTSQL_Grouped	Similar to SQLProfilerStandard, but with information grouped and organized. Use as a start point for general monitoring and troubleshooting.	Because this template groups information by user, it can be used to track requests specific to a problematic user. An example is an application that uses Windows® authentication to connect to SQL Server, where problems are occurring that relate to a specific user.
SQLProfilerTSQL_Replay	Captures events that can be used to replay the exact steps at a later stage or on another server.	Use to troubleshoot and reproduce problems.
SQLProfilerTSQL_SPs	Provides extensive logging for stored procedures, including queries executed within stored procedures.	Use to troubleshoot stored procedures.
SQLProfilerTuning	Contains events needed to capture the execution cost and related data.	Use to track query costs.

The remainder of this How To shows you how to profile two common performance-related scenarios using SQL Profiler.

Isolating a Long-Running Query with SQL Profiler

If your application has a performance problem that you think might be caused by a particularly long-running query, you can use the SQLProfilerTSQL_Duration template to analyze query durations. You can either analyze the queries interactively, or you can save information to an output file and analyze the data offline.

Identifying a Long-Running Query Interactively

The most immediate way of analyzing query performance is to use SQL Profiler to show trace information interactively.

To identify a long-running query interactively

Start SQL Profiler.
On the File menu, click New, and then click Trace.
Specify the relevant connection details to connect to the computer running SQL Server.
The Trace Properties dialog box appears.
In the Template name list, click SQLProfilerTSQL_Duration.
Click the Events tab.
Notice that two key events are selected:
- RPC:Completed from the Stored Procedures event class
- SQL:BatchCompleted from the T-SQL event class
Click Run to run the trace.
Start SQL Query Analyzer.

Run the queries you want to analyze. For example, using the Pubs database, you might run the following query.

select au_id, au_lname + ' ' + au_fname, phone from authors where au_lname like 'G%' order by au_lname
select * from authors
Select au_id from authors

View the trace output in SQL Profiler. Note that durations are given in milliseconds.
Figure 1 shows sample output.

Figure 1: Sample SQL Profiler output using the SQLProfilerTSQL_Duration template
Stop the trace.
Note Your duration times may vary from those shown, and may even appear as zero if the database server has a small load.

Identifying a Long-Running Query from Trace Output

As an alternative to the interactive approach, you can save trace information to an output file and analyze the data offline. The trace information can then be imported into a database table for further analysis. This approach is useful where large sets of trace data need to be analyzed.

The following steps show you how to save trace data to a trace file and then import it into a trace table for analysis. A stored procedure named AnlzTrcExec is provided to aid in data analysis.

Note When trace data is saved to a file, the values in the EventClass column are converted into integer values. To increase readability, the AnlzTrcExec procedure uses a lookup table named trace_events so that the event class can be displayed as text.

To identify a long-running query from trace output

In SQL Profiler, on the File menu, click New, and then click Trace.
Specify the relevant connection details to connect to the computer running SQL Server.
The Trace Properties dialog box appears.
In the Template name list, select SQLProfilerTSQL_Duration.
Select the Save to file check box, specify the trace file name as c:\MyTrace.trc, and then click Save.
On the Data Columns tab, select the following data columns, clicking Add after each selection:
- CPU
- IntegerData
- Reads
- StartTime
- Writes
Click Run.

In SQL Query Analyzer, run the queries you want to analyze. For example, using the Pubs database, you might run the following query.

select au_id, au_lname + ' ' + au_fname, phone from authors where au_lname like 'G%' order by au_lname
select * from authors
Select au_id from authors

Stop the trace.
In SQL Query Analyzer, import the trace file into the database of your choice by using the following query:
SELECT * INTO MyTraceTable FROM ::fn_trace_gettable('C:\MyTrace.trc', default)

Run the following query to create a trace events lookup table.

if exists (select * from dbo.sysobjects
    where id = object_id(N'[trace_events]') and OBJECTPROPERTY(id, N'IsUserTable') = 1)
    drop table [trace_events]
 create table trace_events ([EventClass] int, [EventName] varchar(31))
 Insert trace_events values (10,'RPC:Completed')
 Insert trace_events values (11,'RPC:Starting')
 Insert trace_events values (12,'SQL:BatchCompleted')
 Insert trace_events values (13,'SQL:BatchStarting')
 Insert trace_events values (14,'Login')
 Insert trace_events values (15,'Logout')
 Insert trace_events values (16,'Attention')
 Insert trace_events values (17,'ExistingConnection')
 Insert trace_events values (18,'ServiceControl')
 Insert trace_events values (19,'DTCTransaction')
 Insert trace_events values (20,'Login Failed')
 Insert trace_events values (21,'EventLog')
 Insert trace_events values (22,'ErrorLog')
 Insert trace_events values (23,'Lock:Released')
 Insert trace_events values (24,'Lock:Acquired')
 Insert trace_events values (25,'Lock:Deadlock')
 Insert trace_events values (26,'Lock:Cancel')
 Insert trace_events values (27,'Lock:Timeout')
 Insert trace_events values (28,'DOP Event')
 Insert trace_events values (33,'Exception')
 Insert trace_events values (34,'SP:CacheMiss')
 Insert trace_events values (35,'SP:CacheInsert')
 Insert trace_events values (36,'SP:CacheRemove')
 Insert trace_events values (37,'SP:Recompile')
 Insert trace_events values (38,'SP:CacheHit')
 Insert trace_events values (39,'SP:ExecContextHit')
 Insert trace_events values (40,'SQL:StmtStarting')
 Insert trace_events values (41,'SQL:StmtCompleted')
 Insert trace_events values (42,'SP:Starting')
 Insert trace_events values (43,'SP:Completed')
 Insert trace_events values (44,'Reserved ')
 Insert trace_events values (45,'Reserved ')
 Insert trace_events values (46,'Object:Created')
 Insert trace_events values (47,'Object:Deleted')
 Insert trace_events values (48,'Reserved')
 Insert trace_events values (49,'Reserved')
 Insert trace_events values (50,'SQL Transaction')
 Insert trace_events values (51,'Scan:Started')
 Insert trace_events values (52,'Scan:Stopped')
 Insert trace_events values (53,'CursorOpen')
 Insert trace_events values (54,'Transaction Log')
 Insert trace_events values (55,'Hash Warning')
 Insert trace_events values (58,'Auto Update Stats')
 Insert trace_events values (59,'Lock:Deadlock Chain')
 Insert trace_events values (60,'Lock:Escalation')
 Insert trace_events values (61,'OLE DB Errors')
 Insert trace_events values (67,'Execution Warnings')
 Insert trace_events values (68,'Execution Plan')
 Insert trace_events values (69,'Sort Warnings')
 Insert trace_events values (70,'CursorPrepare')
 Insert trace_events values (71,'Prepare SQL')
 Insert trace_events values (72,'Exec Prepared SQL')
 Insert trace_events values (73,'Unprepare SQL')
 Insert trace_events values (74,'CursorExecute')
 Insert trace_events values (75,'CursorRecompile')
 Insert trace_events values (76,'CursorImplicitConversion')
 Insert trace_events values (77,'CursorUnprepare')
 Insert trace_events values (78,'CursorClose')
 Insert trace_events values (79,'Missing Column Statistics')
 Insert trace_events values (80,'Missing Join Predicate')
 Insert trace_events values (81,'Server Memory Change')
 Insert trace_events values (82,'User Configurable')
 Insert trace_events values (83,'User Configurable')
 Insert trace_events values (84,'User Configurable')
 Insert trace_events values (85,'User Configurable')
 Insert trace_events values (86,'User Configurable')
 Insert trace_events values (87,'User Configurable')
 Insert trace_events values (88,'User Configurable')
 Insert trace_events values (89,'User Configurable')
 Insert trace_events values (90,'User Configurable')
 Insert trace_events values (91,'User Configurable')
 Insert trace_events values (92,'Data File Auto Grow')
 Insert trace_events values (93,'Log File Auto Grow')
 Insert trace_events values (94,'Data File Auto Shrink')
 Insert trace_events values (95,'Log File Auto Shrink')
 Insert trace_events values (96,'Show Plan Text')
 Insert trace_events values (97,'Show Plan ALL')
 Insert trace_events values (98,'Show Plan Statistics')
 Insert trace_events values (99,'Reserved')
 Insert trace_events values (100,'RPC Output Parameter')
 Insert trace_events values (101,'Reserved')
 Insert trace_events values (102,'Audit Statement GDR')
 Insert trace_events values (103,'Audit Object GDR')
 Insert trace_events values (104,'Audit Add/Drop Login')
 Insert trace_events values (105,'Audit Login GDR')
 Insert trace_events values (106,'Audit Login Change Property')
 Insert trace_events values (107,'Audit Login Change Password')
 Insert trace_events values (108,'Audit Add Login to Server Role')
 Insert trace_events values (109,'Audit Add DB User')
 Insert trace_events values (110,'Audit Add Member to DB')
 Insert trace_events values (111,'Audit Add/Drop Role')
 Insert trace_events values (112,'App Role Pass Change')
 Insert trace_events values (113,'Audit Statement Permission')
 Insert trace_events values (114,'Audit Object Permission')
 Insert trace_events values (115,'Audit Backup/Restore')
 Insert trace_events values (116,'Audit DBCC')
 Insert trace_events values (117,'Audit Change Audit')
 Insert trace_events values (118,'Audit Object Derived Permission')
 Go

Create a stored procedure named AnlzTrcExec by running the following code:

if exists (select * from dbo.sysobjects where id = object_id(N'[dbo].[AnlzTrcExec]') and OBJECTPROPERTY(id, N'IsProcedure') = 1)
 drop procedure [dbo].[AnlzTrcExec]
 GO
 
 Create  Proc AnlzTrcExec @trc nvarchar(255), @len int = 60, @Top int = 100, @EventClass nvarchar(20) = 'all', @TextData nvarchar(255) = 'none' as
 declare @cmd nvarchar(2048)
 declare @TopV as nvarchar(20)
 SET @TopV = ' 100 PERCENT '
 if @Top != 100
 BEGIN
   SET @TopV = ' ' + cast(@Top as nvarchar(4)) + ' '
 END
 set @cmd = ' SELECT TOP' + @TopV + ' e.EventName,
 Count(*) as CountOfEvents,AVG(Duration) AS AvgDuration,MIN(Duration) AS MinDuration,MAX(Duration) AS MaxDuration,
 SUM(a.Duration) AS [SumDuration],SUBSTRING(a.TextData, 1, '+ cast(@Len as nvarchar(4)) + ') AS [Substring from Text Data],
 MIN(starttime) as MinStartTime,MAX(starttime) as MaxStartTime,AVG(CPU) AS AvgCPU,MIN(CPU) AS MinCPU,MAX(CPU) AS MaxCPU,
 AVG(Reads)AS AvgReads,MIN(Reads) AS MinReads,MAX(Reads) AS MaxReads,AVG(Writes) AS AvgWrites,MIN(Writes) AS MinWrites,
 MAX(Writes) AS MaxWrite,AVG(IntegerData) AS AvgIntegerData,MIN(IntegerData) AS MinIntegerData,MAX(IntegerData) AS MaxIntegerData
   FROM dbo.' + @Trc +' a LEFT OUTER JOIN
        dbo.trace_events e
     ON a.EventClass = e.EventClass
   WHERE 1=1'
 if @textdata != 'none'
 begin
   set @cmd = @cmd + ' AND a.TextData like ''%' + @TextData + '%'
 end
 if @eventclass != 'all'
 begin
  set @cmd = @cmd + ' AND a.EventClass IN (' + @EventClass + ')'
 end
   set @cmd = @cmd + 
 ' GROUP BY SUBSTRING(a.TextData, 1, '+ cast(@Len as nvarchar(4)) + '), e.EventName
   HAVING (SUM(a.Duration) > 0)
   ORDER BY SUM(a.Duration) DESC'
   exec(@cmd)
GO

Note The AnlzTrcExec procedure is used to analyze the trace events used within this How To. It uses the trace_events table to provide English output names for the EventClass column and also provides several summary options. The stored procedure takes up to four parameters: trace table name, number of characters to group on from the query text, number of queries to return information for, and event class name. Only the trace table name is required.

Run the stored procedure using the following statement.
AnlzTrcExec 'MyTraceTable'
Trace data is displayed using default options.
Note Only queries with a nonzero duration are shown in the summary information.
Run the following query.
AnlzTrcExec 'MyTraceTable', 20, 10, 41
The top 10 'SQL:StmtCompleted' events are returned (ordered by the sum of duration) grouped on the first 20 characters of each query text.

Filtering Events

You can use a filter to view only those queries that take longer than a specified duration.

To filter based on duration

Stop the trace if it is currently running, either by clicking the Stop selected trace icon on the toolbar or by clicking Stop Trace on the File menu.
On the File menu, click Properties.
The Trace Properties dialog box appears.
On the Filters tab, expand Duration from Trace event criteria, and then expand Greater than or equal to and enter a value.. A value of 1000 milliseconds, for example, would cause the filter to show only those queries that take longer than one second to run.
Click Run.

Run the queries you want to analyze. For example, using the Pubs database:

select au_id, au_lname + ' ' + au_fname, phone from authors where au_lname like 'G%' order by au_lname
select * from authors
Select au_id from authors

Using SQL Profiler, view the trace data. Only information satisfying the filter is captured.

After capturing trace information, you can click the Duration column in the output window to sort in order of duration. You can view the slowest-running queries in the TextData column.

Note If no queries match the filter, you may need to lower the value for the Greater than or equal to value.

Tracking Heavily Used Stored Procedures

If your application uses numerous stored procedures, you may want to target your fine-tuning to those stored procedures that are used most heavily. The SQLProfilerSP_Counts template aids in this process, as described in the steps that follow.

To track heavily used stored procedures

Start SQL Profiler.
On the File menu, click New, and then click Trace.
Specify the relevant connection details to connect to the computer running SQL Server.
The Trace Properties dialog box appears.
In the Template name list, select SQLProfilerSP_Counts.
Click Run to run the trace.
Running the trace displays the following events: EventClass, ServerName, DatabaseID, ObjectID and SPID.
The most frequently referenced ObjectIDs are listed first.
You can now run your client application and begin database profiling. Figure 2 shows sample output.

Figure 2: Sample SQL Profiler output using the SQLProfilerSP_Counts template

Identifying Stored Procedures

To find the name of the stored procedure given a specific ObjectID, you can use the following query. Replace <ObjectID> with the value you see in the SQL Profiler output window.

Select name from sysobjects where id = <ObjectID>

Identifying Execution Duration

If you want to find out how long a stored procedure took to run, you need to capture the SP:Completed event. To identify the execution duration of individual statements within a stored procedure, use SP:StmtCompleted.

To identify stored procedure execution duration

Stop the trace if it is already running.
On the File menu, click Properties.
On the Events tab, expand the Stored procedures event class present in the Available Event Class list box and select SP:Completed.
Click Add, and then click Run.
Run the stored procedures you want to analyze. For example, using SQL Query Analyzer and the Pubs database:
sp_help authors
SQL Query Analyzer displays a list of stored procedure executions.

To identify statement execution duration within a stored procedure

Stop the trace if it is already running.
On the File menu, click Properties.
On the Events tab, expand the Stored Procedures event class and select SP:StmtCompleted.
Click Add, and then click Run.
SQL Profiler shows statement and stored procedure execution.
Run the stored procedures you want to analyze. For example, using SQL Query Analyzer and the Pubs database:
sp_help authors
SQL Query Analyzer displays a list of statement executions.

Additional Resources

For more information, see the following resources:

For a printable checklist, see "Checklist: SQL Server Performance" in the "Checklists" section of this guide.
Chapter 14, "Improving SQL Server Performance"
For more information about using SQL Profiler, see Microsoft Knowledge Base Article 325297, "Support WebCast: How to Effectively Use SQL Server Profiler," at http://support.microsoft.com/default.aspx?scid=kb;en-us;325297.

Manage Your Profile | Legal | Contact Us | MSDN Flash Newsletter

Product Families

Resources

About Microsoft

Popular Places

Popular Searches

Popular Downloads