DEBUG Stored Procedures Using PRINT or RAISERROR in TSQL

DEBUG Stored Procedures Using PRINT or RAISERROR in TSQL

By Strictly Software 

Usually when I am having to write stored procedures with many sections within a transaction I set a @DEBUG BIT variable at the top of the procedure to help with debug.

Then I add checks to see if it is enabled and at various points in the procedure, usually at the start and end plus before and after each block of code I would output some debug telling me what is going on.

This really helps me when I have problems with the procedure and need to know where any bug is happening.

An example of a basic stored procedure with transactions so I can rollback the code if something goes wrong, plus the use of a TRY CATCH so that I can log error details to a table is shown below.

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO

CREATE PROCEDURE [dbo].[usp_net_clean_up]
	@SitePK int
AS
BEGIN
	
	SET NOCOUNT ON;

	DECLARE @ROWS INT,			
		@DEBUG BIT

	SELECT @DEBUG = 1

	IF @DEBUG = 1
	  PRINT 'IN usp_net_clean_up - SitePK: ' + CAST(@SitePK as varchar)

	BEGIN TRAN

	BEGIN TRY

        UPDATE	NIGHTLY_JOBS
	SET	Pending = 0
	WHERE	SitePK = @SitePK

	-- capture data errors
	SELECT @ROWS = @@ROWCOUNT

	IF @ROWS = 0 OR @ERROR != 0
	  BEGIN
		IF @DEBUG = 1
		  PRINT 'No rows updated'

		GOTO HANDLE_ERROR
	  END

	UPDATE	LOCK_FILES
	SET	Locked = 0
	WHERE	Locked = 1
		AND SitePK = @SitePK
		AND DATEDIFF(Day,Stamp,GETDATE())=0

	SELECT @ROWS = @@ROWCOUNT

	IF @ROWS = 0 OR @ERROR != 0
	  BEGIN
		IF @DEBUG = 1
		  PRINT 'No rows updated'

		GOTO HANDLE_ERROR
	  END

	END TRY
	BEGIN CATCH
		
		IF @DEBUG = 1
		  BEGIN
			PRINT 'IN CATCH ERROR'
			PRINT ERROR_MESSAGE()
			PRINT ERROR_LINE()
		  END

		 -- all ERROR functions will be available inside this proc
		  EXEC dbo.usp_sql_log_error @SitePK

		  -- rollback after anything you want to do such as logging the error 
		  -- to a table as that will get rolled back as well if you don't!
		  IF @@TRANCOUNT > 0
		    ROLLBACK TRAN

		  GOTO HANDLE_ERROR
	END CATCH

	IF @DEBUG = 1
	  PRINT 'End of proc - no errors'

	IF @@TRANCOUNT > 0
	  COMMIT TRAN

	GOTO EXIT_PROC


	HANDLE_ERROR:
	  IF @DEBUG = 1
	    PRINT 'IN HANDLE ERROR'

	  RETURN 1 -- I use 1 for success despite SQL recommendations!

	EXIT_PROC:
	  IF @DEBUG = 1
	    PRINT 'IN EXIT_PROC'

	  RETURN 0 -- failure
END

However another way to output debug messages is with the RAISERROR function and the use of placeholders for values, a bit like the sprint function in PHP.

To be honest I only used the function previously to raise custom errors but you easily use it for debugging as well.

This is an example of a super fast way to insert 100,000 rows into a table (using the TEMPDB), and using RAISERROR to output debug messages related to the time it takes plus some examples of the placeholder types which are listed at the bottom of the page.

SET NOCOUNT ON
SET DATEFORMAT YMD

DECLARE @StartStamp VARCHAR(20),
	@StopStamp VARCHAR(20),
	@ROWS INT

SELECT @StartStamp = CONVERT(varchar, GETDATE(),13)

RAISERROR('Start insert at %s',0,1,@StartStamp) WITH NOWAIT;

-- ensure our table doesn't already exist
IF OBJECT_ID('tempdb.dbo.random_data','U') IS NOT NULL
  DROP TABLE tempdb.dbo.random_data;

RAISERROR('Start insert of data',0,1)

-- super fast insert of 100,000 rows into a table
SELECT TOP (100000)
        RowNo   = ISNULL(CAST( ROW_NUMBER() OVER (ORDER BY (SELECT 1)) AS INT),0),        
        RandomID = NEWID() 
INTO	tempdb.dbo.random_data
FROM	master.sys.all_columns ac1
CROSS JOIN master.sys.all_columns ac2
CROSS JOIN master.sys.all_columns ac3

SELECT @ROWS = @@ROWCOUNT, @StopStamp = CONVERT(varchar, GETDATE(),13)

RAISERROR('There are %d rows in the table. Error Code was %u. Insert completed at %s',0,1,@ROWS,@@ERROR,@StopStamp) WITH NOWAIT;

-- output results
SELECT * FROM tempdb.dbo.random_data

-- drop our table
DROP TABLE tempdb.dbo.random_data;

-- ensure it is dropped
IF OBJECT_ID('tempdb.dbo.random_data','U') IS NULL
  RAISERROR('Dropped table %s',0,1,'tempdb.dbo.random_data')
ELSE
  RAISERROR('Could not drop table %s',0,1,'tempdb.dbo.random_data')

When I run this code the debug in the messages tab of SQL Query Analyser are:

09 Jul 2015 11:37:18
Start insert at 09 Jul 2015 11:37:18
Start insert of data
There are 100000 rows in the table. Error Code was 0. Insert completed at 09 Jul 2015 11:37:18
Dropped table tempdb.dbo.random_data

As you can see you can enter multiple parameters into the RAISERROR function.

The only thing you must remember is that you cannot use functions such as GETDATE(), CONVERT() or CAST() as substitution values. They must all be literals which is why I am converting the time stamps into strings first.

I hope you also notice how fast the insert of 100,000 rows all with unique values in the 2nd column is.

It takes less than one second!

This method is much faster than any WHILE loop or CURSOR method to insert records and you should add it to your box of tricks for future use.

Some people use number tables for insert jobs like this but there is no need when you have system tables with thousands of rows within them.

The trick is to use two CROSS JOINS to to the system tables master.sys.all_columns to create the necessary rows for the insert.

CROSS JOINS are hardly used by many people but they are very useful when you need to do insert jobs like this quickly.

Note how each row is ordered sequentially from 1 to 100,000 and the 2nd column has a unique GUID inside it. This is created from the NEWID() function.

So these are just two methods for adding debug to your TSQL code and it is up to you which method you find the most useful for the job at hand.

RAISERROR function parameter substitution values

%d or %i = signed integer

%o = unsigned octal

%p = pointer

%s = string

%u = unsigned integer

%x or %X = unsigned hexadecimal

By Strictly Software 

© 2015 Strictly Software