Quotable
SQL Server is pretty good at a lot of things, but there’s no great way to debug logic or performance issues in longer stored procedures.
Whenever I’m writing a stored procedure, especially when dynamic SQL is involved, I add in a debug parameter. Sometimes I’ll do something more granular, and add in specific parameters for debugging performance vs debugging other things, like:
- Temp table contents
- Parameter values
- Variable values
- Loop progress
- Current dynamic statement
- Current point in the stored procedure (sometimes with a time stamp)
This can really save your hide when you hit a reproducible issue. Proper error handling is part of proper debugging, too.
I generally detest PowerShell, but I love that some commands have a -WhatIf parameter to test what would happen. For normal SQL Server queries, you don’t get that.
But if you’re writing dynamic SQL that may execute database commands (backup, checkdb, settings changes, etc.), you should also include a parameter that prevents dynamic SQL execution so you can debug without worrying about wreaking havoc.
Should You Use XACT_ABORT?
This depends a little bit. You probably want to use this in 99% of the stored procedures that you write that contain more than a single select statement.
The only case I can think of where you wouldn’t want to use this is in a set of informational queries where one of them failing is inconsequential.
A good example of this is sp_PressureDetector, where you want all the other results even if one of the individual queries fails for some reason.
This might make some results look weird sometimes, if there’s an error when you’re populating a temp table for example, where it ends up empty because of some population failure.
Later on, when you select from it or join to it, the results may be disappointing.
PRINT vs RAISERROR
In most cases, RAISERROR is your best choice for debugging (I’m not talking about error handling best practices here).
Despite some frustrations with it, it’s the easiest way to debug most state conditions for parameters, variables, and overall procedure progress.
The main problem with it is that there’s a maximum error message length of 2,047. This can be less than ideal when you’re dealing with debugging long dynamic SQL statements.
Then you’re looking at using a stored procedure like Helper_LongPrint, or rolling your own PRINT/SUBSTRING combination (maybe even in a loop) to output the full query.
A simplified version would look something like this:
DECLARE
@s nvarchar(MAX) = REPLICATE('A', 4000) + REPLICATE('B', 4000),
@len bigint = 0,
@block bigint = 1;
SELECT
@len = LEN(@s);
WHILE @block < @len
BEGIN
PRINT SUBSTRING(@s, @block, 4000)
SELECT
@block += 4000
END;
Admittedly, I usually just brute force long printing in most of my stored procedures because I have a good sense of how long the output query will be.
If yours will vary, the looping option is the best choice.
Table Of Contents
If you populate temporary objects in your stored procedures, it’s a helpful debugging step to view the contents to make sure they’re correct, or… even there at all!
This is how I do it when I’m feeling really motivated:
- Check to see if there’s anything in the temp table
- Select the contents of the temp table
- Add an extra column to the select list to tell me which temp table I’m selecting from
- If it’s empty, select a different message to tell me that
CREATE TABLE
#
(
_ sql_variant
);
DECLARE
@debug bit = 1;
IF @debug = 1
BEGIN
IF EXISTS
(
SELECT
1/0
FROM # AS _
)
BEGIN
SELECT
table_name = '#',
_.*
FROM # AS _;
END;
ELSE
BEGIN
SELECT
info = '# is empty!'
END
END;
This is especially useful when there are a lot of temp tables involved.
Depending on the procedure, sometimes I’ll put this right after the temp table is populated, other times I’ll put all of the temp tables used at the end.
Valuables
I often find myself declaring variables and setting them to the result of a select, and sometimes manipulating passed in parameters.
To make sure they’re ending up as I expect them to, I’ll usually stick something like this at the end of the procedure to validate them:
DECLARE
@a int = 1,
@b int = 2;
IF @debug = 1
BEGIN
SELECT
a = @a,
b = @b;
END;
This can help you figure out where things are going right, wrong, sideways, pear shaped, or plaid.
If there’s a loop involved, I’ll stick them inside there to make sure we’re progressing, and I didn’t do anything stupid that got me stuck inside a loop of the infinite variety.
Inside a loop, I’ll use RAISERROR. You can see that in sp_LogHunter.
It’s a good time. A cursor inside a while loop.
Don’t tell anyone.
Progress Bar
Sometimes it’s helpful to know which point in a stored procedure, or some branched code you’ve hit.
This is admittedly fueled in part by self-gratification. Seeing things make progress successfully, do the right thing, and loops work and finish is quite satisfying.
That’s why I’ll stick little waypoints in my procedures like this:
IF @debug = 1
BEGIN
RAISERROR('We did it!', 0, 1) WITH NOWAIT;
END;
Again, strongly prefer RAISERROR to PRINT here, because the WITH NOWAIT line just about guarantees the message will show up when it happens.
Print statements can get stuck waiting for buffers and other oddities before showing up.
But Is It Fast?
Stored procedures are often full of tiny little queries that don’t really matter, and in really long stored procedures, returning a plan to SSMS for every single query that runs is a recipe for crashsaster.
If I have no idea what’s slow, I’ll use sp_HumanEvents to troubleshoot performance.
But I usually have a sense of which parts can get slow, so I’ll add performance feedback to the list, too.
IF @debug = 1
BEGIN
SELECT
query = 'starting super important query now!',
start_time = SYSDATETIME();
SET STATISTICS XML ON;
END;
SELECT
x = 'this is a super important query';
IF @debug = 1
BEGIN
SELECT
query = 'finished super important query now!',
end_time = SYSDATETIME();
SET STATISTICS XML OFF;
END;
Since there are usual multiple queries that I’m interested in, I find it good to add a select to tell me which query the plan is for in the results so that I know which one to click on.
Adding in the start and end times is a good way to quickly identify which returned plan(s) took the longest.
It’s A Lot Like Life
Adding in good debugging steps certainly adds more time and effort to the process, but it pays off when you have to figure out what’s going wrong.
You probably don’t need it in every single stored procedure, especially the simple ones, but the longer and more involved your code gets, the more critical this becomes.
A lot of this comes from my experiences working on open source scripts that other folks might have to troubleshoot someday. You’re not only doing yourself a favor, but you’re helping anyone else who needs to work on your code.
Thanks for reading!
Going Further
If this is the kind of SQL Server stuff you love learning about, you’ll love my training. I’m offering a 75% discount to my blog readers if you click from here. I’m also available for consulting if you just don’t have time for that, and need to solve database performance problems quickly. You can also get a quick, low cost health check with no phone time required.
