How to add tracing/debug output to stored procedures in Sql Server (2008)

Question

What is the closest to being able to add log4net style debug information to a set of stored procedures? Some of procedures delegate work to other procedures and I want trace information from both.

I've sprinkled print and select statements through while developing them, and ideally would like to be able to run the proc in different modes depending on whether it's normal operation of troubleshooting and get more or less output.

In this particular case the primary stored proc will be run repeatedly from an agent job, but may be run from management studio when troubleshooting.

The procs already use an error log table and email facilities to catch raised errors. The kind of thing I'm looking to be able to track down is where an input data issue means the output data is wrong but the procs don't fail completely, and it would be useful to see exactly what was done at each step.

What approaches do you know of for producing meaningful and ideally filterable output?

One per answer so we can see the final rankings ;-)

Out of the box answers welcome, such as "don't - step through with management studio when you need to"

Solution 1

Piles of print statements

eg

print 'Doing something...'
INSERT INTO foo(a) VALUES(1)
print @@ROWCOUNT

This answer just for balance, seeing as it's quiet round here.

Solution 2

One approach might be to check if the proc is being run from SSMS and fire some Custom user configurable SQL Server Profiler events if so. e.g.

CREATE PROC foo
AS
DECLARE @debug bit = CASE WHEN APP_NAME() = 'Microsoft SQL Server Management Studio - Query' 
                          THEN 1 
                          ELSE 0 END

DECLARE @userinfo nvarchar(128)
DECLARE @userdata varbinary(8000)

--Do some work here

IF @debug = 1
BEGIN
--Do some custom logging 
    SET @userinfo = N'Some custom info'
    SET @userdata = CAST('Some custom data' AS varbinary(8000))
    EXEC sp_trace_generateevent @eventid = 82 /*Use 82-91*/
                               ,@userinfo = @userinfo 
                               ,@userdata = @userdata

END

---

Though in practice I usually use something like the below. Sometimes with additional code to log the message (and possibly step and status values) to a table depending on requirements. This would allow the "filterable" requirement to be met.

This stops the message being printed out except if the APP_NAME indicates it is being run in (an English language version of) SSMS and uses NOWAIT so the message gets printed out immediately rather than waiting for the buffer to fill.

CREATE PROCEDURE [dbo].[PrintMessage] @message            NVARCHAR(MAX),
                                      @PrependCurrentTime BIT = 0
AS
    IF APP_NAME() LIKE 'Microsoft SQL Server Management Studio%' 
      BEGIN
          DECLARE @CurrentTimeString VARCHAR(30);

          SET @CurrentTimeString = ''

          IF @PrependCurrentTime = 1
            BEGIN
                SET @CurrentTimeString = CONVERT(VARCHAR(19), GETDATE(), 20) + ' '
            END

          RAISERROR('%s%s',0,1,@CurrentTimeString,@message) WITH NOWAIT

      END

Solution 3

Don't add tracing output, instead just step through as needed with the sql server management studio debugger.

(Added to see if people prefer this)