Deciphering Trace Output

From SQLServerPedia

Jump to: navigation, search

See Also: Main_Page - Performance Tuning - SQL Server Profiler

How to Interpret Profiler Results

In this eleven minute video, Brent walks through four examples of performance problems he had, and shows how he figured out his mitigation solutions for each problem.

http://tutorials.sqlserverpedia.com/SQLServerPedia-20090224-ProfilerExamples.flv

For more tutorial videos like this, check out the SQL Server Tutorials page.

Analyzing SQL Server Profile Traces

Capturing traces is relatively straightforward; interpreting the Profiler's output is not however. On busy servers the trace files can easily grow to multiple gigabytes. Therefore, you must take great care to apply as many filters as possible while still getting the needed information. Once you have a trace, you can examine it within the Profiler or by querying a trace saved as a SQL Server table.

Profiler has a useful search functionality that helps you find particular piece of information you're looking for. To activate such a search, simply choose Edit --> Find within the Profiler. The "Search value" is the string that you are looking for. Data column lets you specify the particular data column you wish to find the search value in. If you don't specify the data column then all columns within the current trace will be searched. The Find Next and Find Previous buttons let you find the same piece of information again. The search functionality within the Profiler is great for finding execution of the same stored procedure or events caused by the same login. The limitation of this tool is that you cannot order or group data within the trace once it is collected.

If you wish to perform a more extensive analysis of the captured trace you should save its output as a SQL Server table. To do so, choose File --> Save As --> Trace Table within the Profiler. You will be asked to provide the server name where you wish to save the trace to and valid login credentials. Once you connect to the server you must also provide the database name and table name where trace should be saved. You can choose an existing table as the destination for the trace, so long as it has the same structure (data columns) as the trace. Keep in mind however, that saving a trace as a SQL Server table can be a resource and time intensive operation. The trace that contains millions of rows might take a while to save as a table. Therefore, avoid saving traces to production SQL Servers.

Once you have saved a trace as a table you can treat it as any other SQL Server table - you can build indexes, add and remove columns, build views on top of this table and so forth. The main advantage of saving a trace as a table is the extensive searching and sorting capabilities available with TSQL. For example, to return all events generated by SQL Server Enterprise Manager from the saved trace you could execute the following query: 

SELECT * FROM replay_trace WHERE ApplicationName = 'MS SQLEM'

If you wish to see events in the order of their duration and CPU time taken, simply order the output by those columns: 

SELECT * FROM replay_trace WHERE ApplicationName = 'MS SQLEM' ORDER BY duration, CPU

Here is a SELECT statement that will return the least, greatest and average execution time for each captured event, along with the total number of executions of that query. The output is ordered by the total number of times a particular statement was executed. This statement is useful for identifying the longest running queries; therefore it limits the output only to those events that have reported the duration of 1 or more milliseconds: 

SELECT MAX(duration) AS MaximumExecutiontime, MIN(duration) AS MinimumExecutiontime, AVG(duration) AS AverageExecutiontime, COUNT(*) AS NumberOfTimes, SUBSTRING(TextData, 1, 255) AS QueryText
FROM trace 
/* eliminate those events that don't report duration or report 0 milliseconds */ 
WHERE duration > 0 AND duration IS NOT NULL GROUP BY SUBSTRING(TextData, 1, 255) ORDER BY 3 DESC

Notice that TextData column has a data type of TEXT and therefore cannot be used within GROUP BY statements unless you apply a SUBSTRING function first. That is why the statement above only brings back the first 255 characters of the text data column. Notice also that when you save the trace as a table, the event class column is automatically converted to the event number. If you wish to limit the query output by event class you must use event numbers. For example, the following query limits results by event number 41, which is SQL: StmtCompleted: 

SELECT * FROM trace1 WHERE EventClass = 41 /* SQL: Stmt Completed */ 
ORDER BY duration DESC

Please refer to the table of events for event numbers.

You can write queries similar to the above to find the statements that took up the most CPU time, performed the most disk reads and writes and so forth. Writing SQL statements against the trace saved as a SQL Server table can be a powerful tool for deciphering the trace output.

SQLServerPedia Articles on Profiler

Retrieved from "http://www.sqlserverpedia.com/wiki/Deciphering_Trace_Output"