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.
Nice post, Erik. I use most of these great techniques you posted. This will help a whole lot of people and now I also have a place to point people to instead of ‘splainin’ it again!
Aw, thanks Jeff! Appreciate the kind words. Doing this stuff up front has saved a baked noodle many times.
Hi Erik,
Nice tips, what I sometimes do with looping dynamic sql is add the index values as part of the statement ‘insert .. /* loop: x of y */ ..’ so in sp_whoisactive you see the index values were the loop is..
Met vr. gr. Ronald
Yes, I also do that when it’s sensible, like in sp_LogHunter.
Absolutely concur with this post. One other trick I use when I need to grab some debugging data from a table is to use “select … for XML” to extract the row contents into a string that I can return or print. Much easier than retrieving individual columns and dealing with different data types.
Ooh, that’s a nifty idea! I use that to return more compact results for some things. I’m gonna look for ways to use it like you’re talking about, too.
Thanks!
I put a comment with a
–DECLARE @x INT = 21, @from DATE = ‘20230901’ …;
before every statement, with every variable and a meaningful value that is used in this statement (@x and @from are just examples here; if it is an INSERT statment I often add a DELETE / TRUNCATE to the comment too)
This way I can easily execute the whole procedure step by step manually by selecting the comment without the leading dashes. And can do whatever checks (of the #temp-tables etc.) before I go to the next statement. And with search + replace I can often simply replace the ids, dates etc with a more current value.
PS: you have a TERRIBLE naming style in the example of the “Table Of Contents” section :-). I really hope no junior uses your proof-of-concept there as example for real code.