How to debug a stored procedure using print statements and time analyses for each statement?

6.3K Asked by JosephSlater in SQL Server , Asked on Jan 16, 2020

Print statements can be used to set the print in between the statements where we need to see the time taken by the query. Always use a print statement before and one after that so that we can track the time taken in between.

Note: these statements are used only for analyses never run the print statement for the production deployment this is just for checking the current performance as these kinds of statement reduce the performance in micro to milliseconds and takes few amount of memory for output and increase the logs

Below is the sample for the procedure:

alter Procedure usp_test_SaveTrans

Begin

print 'Procedure Started At: '+cast(cast( getdate() as datetime2) as varchar(30))

TRUNCATE TABLE Employ

DECLARE @v_Second_point NCHAR(50)='Trans_Second_point'

BEGIN TRANSACTION

INSERT INTO Employ VALUES ( 1, N'EMP1',200000)

SAVE TRANSACTION First_point

WAITFOR DELAY '00:00:20';

print 'Savepoint after the first INSERT after a delay of 00:00:20 created At: '+cast(cast( getdate() as datetime2) as varchar(30))

INSERT INTO Employ VALUES ( 2, N'EMP2',234000)

WAITFOR DELAY '00:01:07';

SAVE TRANSACTION @v_Second_point

print 'Savepoint after the Second INSERT after a delay of 00:01:07 created At: '+cast(cast( getdate() as datetime2) as varchar(30))

INSERT INTO Employ VALUES ( 3, N'EMP3',500098)

WAITFOR DELAY '00:00:40';

ROLLBACK TRANSACTION @v_Second_point

print 'ROLLBACK TRANSACTION SecondInsert after a delay of 00:00:40 done At: '+cast(cast( getdate() as datetime2) as varchar(30))

COMMIT

SELECT * FROM Employ

print 'End of Procedure done At: '+cast(cast( getdate() as datetime2) as varchar(30))

end

Your Answer

Answers (2)

Ranjana

Debugging a stored procedure can be tricky, especially when you’re trying to identify slow-running parts. Using PRINT statements and tracking execution time for each section can help you diagnose the problem. Here’s a step-by-step approach:

1. Use PRINT Statements for Basic Debugging

Adding PRINT statements at key points in your stored procedure helps you understand which parts of the code are executing.

  PRINT 'Starting procedure execution';

This can help you trace the flow, identify where it might be getting stuck, or isolate logic errors.

2. Use GETDATE() or SYSDATETIME() for Time Tracking

To measure how long each section of your stored procedure takes to run, capture timestamps before and after key blocks of code.

Example:

DECLARE @StartTime DATETIME = GETDATE();  

-- Some SQL code  

PRINT 'Time taken for section 1: ' + CAST(DATEDIFF(MILLISECOND, @StartTime, GETDATE()) AS VARCHAR) + ' ms';

This will print the time elapsed in milliseconds.

3. Identify Bottlenecks with Execution Time

If a particular section is slow, break it down further and add additional PRINT statements and time tracking to identify the specific query or logic causing delays.

4. Use Temporary Tables for Data Insights

If you suspect that large data sets are causing issues, store intermediate results in temporary tables and analyze their size and content.

5. Leverage SQL Profiler (Optional)

For deeper analysis, SQL Profiler (in SQL Server) can help you capture more detailed performance metrics without modifying the stored procedure directly.

2 Days

Ranjana

Debugging a stored procedure can be effectively managed by using print statements and performing time analysis for each statement. Here’s a step-by-step guide:1. Add Print Statements

1. Add Print Statements

Purpose: Print statements help you track the flow of execution and output intermediate results.

How-To:

Insert PRINT statements at key points in the procedure to output variable values, execution checkpoints, and other relevant information.

DECLARE @VariableName INT

SET @VariableName = 10

PRINT 'The value of @VariableName is: ' + CAST(@VariableName AS VARCHAR)

This method helps in understanding the state of variables at various points and the sequence of execution.

2. Time Analysis for Performance

Purpose: Identifying performance bottlenecks by measuring the execution time of each statement.

How-To:

Use the GETDATE() function to record the start and end time around each significant statement or block of statements.

  DECLARE @StartTime DATETIME, @EndTime DATETIMESET @StartTime = GETDATE()-- Your SQL statementSELECT * FROM YourTableSET @EndTime = GETDATE()

PRINT 'Execution time: ' + CAST(DATEDIFF(MILLISECOND, @StartTime, @EndTime) AS VARCHAR) + ' ms'

This will help you pinpoint slow-running queries or operations within your stored procedure.

3. Combine Both Methods

By combining print statements and time analysis, you can not only trace the logic flow but also identify performance issues.

Example:

CREATE PROCEDURE DebugExample

AS

BEGIN

  DECLARE @StartTime DATETIME, @EndTime DATETIME



  PRINT 'Starting the procedure...'  -- Measure time for the first block  SET @StartTime = GETDATE()  -- First block of statements  SELECT * FROM Table1  SET @EndTime = GETDATE()  PRINT 'First block execution time: ' + CAST(DATEDIFF(MILLISECOND, @StartTime, @EndTime) AS VARCHAR) + ' ms'  PRINT 'First block completed.'  -- Measure time for the second block  SET @StartTime = GETDATE()  -- Second block of statements  UPDATE Table2 SET Column1 = 'Value'  SET @EndTime = GETDATE()  PRINT 'Second block execution time: ' + CAST(DATEDIFF(MILLISECOND, @StartTime, @EndTime) AS VARCHAR) + ' ms'  PRINT 'Second block completed.'  PRINT 'Procedure completed.'END

Summary

By strategically placing print statements and measuring execution time, you can effectively debug your stored procedures. This approach allows you to monitor the flow of execution and identify performance bottlenecks, making it easier to optimize and troubleshoot your SQL code.

10 Months