One question I’ve seen popping up a few times recently, is how to check what individual statement(s) within an SQL Server stored procedure are taking the most time.
The scenario is that there is a stored procedure that consists of a number of SQL statements. The stored procedure has been flagged up as running slower than perhaps it was expected to, but as there are a number of statements/queries within it, it’s not immediately clear where the time is being taken.
Now the immediate solution that springs to mind is to check the execution plan as that will show where the time is being spent. Job done.
But in this instance, the question related to how to extract a list of execution times/stats for each statement within a stored procedure and the focus was away from just looking at the execution plan.
One approach mentioned was to record the start and end time either side of each statement and log out to an audit table to then be reviewed. I think this is a bit clunky, and means you have to go in and add potentially a lot of temporary code that needs to be stripped out again later.
Instead, what I think is a better approach is to use SQL Profiler. When you run a standard/default trace it doesn’t capture the execution of each individual statement, just the overall execution of the stored procedure. What you need to do is set up the trace to monitor the SP:StmtCompleted event so that what you end up with is a trace of every statement executed within the stored procedure call. The trace can then of course be saved to file or to a database table if needed.
It’s simple, but effective. I think this particular event class often slips under the radar as it’s (rightly so) not traced by the standard template that most people (including me) tend to use when using SQL Profiler. And unless you’ve looked through all the event classes, you may not know that this was there or what it actually does.