Statement Completed
Profiler is a magnificent tool for capturing the things going on inside your SQL Server instance. Unlike the old days in 7.0 and before, the modern implementation of Profiler can be very unobtrusive within the system. The default set of events and columns will consume well below 1% of resources. What I’m about to show you however, consumes quite a bit more. The best approach is to never run this in a production environment. The second best approach is to run it for very short periods. You’ve been warned. You could negatively impact the performance of your production system if you do this.
When you start Profiler and create a trace, the default settings look like this:
Figure 7
If you click the check box “Show All Events” the screen changes and a lot more options are available. Scroll down until you find one of the following: “SQL:StmtCompleted” inside the TSQL heading if you’re dealing with TSQL queries or “SP:StmtCompeleted” inside the Stored Procedures heading if you’re dealing with procedures. Click the appropriate checkbox so that your screen now looks like this:
Figure 8
When you hit run, Profiler will not only capture the procedures and queries as they run, but each statement within them. It will return a lot of data. But, you should always see a wrapper around your statements. Either a Batch Starting or RPC Starting should precede the list of statements like below:
Figure 9
Here you can see the SQL:BatchStarting and the SQL:StmtCompleted that consist of a stored procedure getting called “EXEC [Staging].[spr_StagePolicyBil…” Then all the individual statements are laid out there. Each one shows the I/O and time that it took (off the screen to the right in the example above). Now you can quickly and easily identify which statement was the most costly and begin to work on it. To work on the query, to begin to tune it, you’ll need an Execution Plan.
You can do that from Profiler too. Go back into the events and scroll up until you find the Performance heading. Under that you can select the event “Showplan XML.” Now when you run your query you’ll see a profiler output that looks something like this:
Figure 10
Yes, you asked for XML and for some reason it’s showing you a graphical execution plan. We’ll discuss that a bit more later. Just be satisfied that you can see the statement completed event and the execution plan, all in one place. If you had to you could move the trace information into a database and perform queries against it to further refine your search for the most costly statement.
What do you do if the execution plan is a lot more complicated than the one displayed above? How are you going to work with it to identify the most costly operations?
Take Out Wrenched Ankle
That’s from an old (real old) kid’s game called Operation. Every icon in an execution plan represents an operation that the query engine is performing to complete the statement defined by the TSQL submitted. Our goal is to find the operation, out of possibly hundreds or more, that is causing all the trouble. The original game of Operation was quite a lot easier but maybe not quite as much fun.
GUI
When you run a query and get an execution plan that looks like this:
Figure 11
You’ve got problems. That mangled mush represents about 600 operations, I think. It’s a bunch. You’re not going to simply look at it and see which operation is the most costly. If you want to browse through the GUI, looking for the most costly operation, you’ll need to be able to see that little plus (+) sign like in the image below:
Figure 12
Click and hold this. It will open a small window that you can scroll through quickly. You’ll find that it allows you to see your whole query. You’ll also find that it’s difficult and tedious to scroll around in the GUI looking for the most costly operation. There has to be a better way.