Saving and Examining Trace Output
You can save and examine trace output in a trace file, SQL script, or a SQL Server table. Perhaps saving as a table allows the most flexibility because you can write queries against a trace table to examine and analyze the output. However, saving as trace files makes traces more portable. If you save the trace file as a SQL script, you only get a file with SQL statements sent to your server; all other data columns are simply discarded.
When troubleshooting performance issues, I prefer saving trace output in a SQL Server table. The reason is that the biggest bang for your buck comes from the SQL statements or routines that execute most frequently and most sluggishly. Performance is in the eyes of your end-users; therefore, if a database routine takes four minutes to complete and is executed 10,000 times daily, the database administrator’s phone is likely to ring off the hook. If you optimize such procedure to execute within 10 seconds, you’ll be sure to make your managers happy. On the other hand, you’re not likely to hear much praise for optimizing a batch job that runs once a night from 2 seconds down to 1.5 seconds. In order to find the top 10 worst performing queries, you can execute the following query against a saved trace table:
SELECT TOP 10 TextData, Duration, StartTime, EndTime FROM trace WHERE duration IS NOT NULL AND duration <> 0 ORDER BY duration DESC
Finding the most frequently executed statements is also fairly easy. The only problem is that TextData column is of TEXT data type; therefore, you can’t easily group by this column. Furthermore, the parameter values for procedures that accept parameters will change from one execution to the next, so you’re not likely to see the same procedure executed with the same set of parameters repeatedly. The workaround for these issues is to grab a portion of the TextData column that won’t change for the same procedure. For example, let’s say you have a procedure called usp_GetCustomerList that takes three parameters. The TextData column recording execution of this procedure might have the following values:
EXEC usp_GetCustomerList 1, 32, 5 EXEC usp_GetCustomerList 193, 3532, 555 EXEC usp_GetCustomerList 419, 322, 425
You can see that the first 24 characters of this column will always be the same regardless of the parameters passed to this procedure. Therefore, we can execute the following query to get a count of each SQL statement (or procedure) and number of times it was executed:
SELECT SUBSTRING(textData, 1, 24), COUNT(*) FROM trace WHERE TextData IS NOT NULL GROUP BY SUBSTRING(textData, 1, 24) ORDER BY 2 DESC
When troubleshooting a particular application that I’m not familiar with, I prefer to examine the contents of the trace directly in the Profiler. This way, I can examine not only the stored procedure call but also the statements included in the procedure. I can also tell if any procedure calls other procedures and examine parameter values passed to each routine.