SQLTeam.com | Weblogs | Forums

Best way to output temp variables to table for debugging


#1

I inherited a huge stored procedure with multiple cursors that have cursors that are calling other stored procedures with cursors in them and it's working, but on occasion it skips a record that should be updated. The file imports that trigger the procedure are pretty long so it's a lot of debugging to step through manually.

So I'm creating a table and adding a bunch of INSERT INTO SELECT parameter values throughout all the procedures to output the value of all the cursor values, temp variables, @@FETCH_STATUS, and anything else at every step that might be causing something to not work as intended.

Is there any other way to output every value change and cursor loop?


#2

Longshot: Is NOLOCK used in the code?

Some variations-on-a-theme, but probably not significantly different ways. There is a single-step type debugger I believe, but I've never used it in anger or heard much about it, so I presume its not the tool-of-choice for most developers when debugging

We have a parameter "@Debug" on all our Sprocs, and then

IF @Debug = 1 THEN SELECT [MySprocName] = 'DEBUG(1)', @Param1, @Param2

debugging statements within the code. If one SProc calls another then it includes the @Debug parameter - so any child-SProcs also output debugging info when passed a non-zero value.

We run the Sproc in SSMS, or similar, when we have a problem to solve and set the @Debug parameter to get the debugging information output. Our preference is to use SELECT for that, and to have the first column aliased to the name of the Sproc (so if one Sproc calls another we can see which one is outputting the debug information) and to have a value in that first column e.g. "DEBUG(1)" which uniquely identifies the location within the Sproc. We might have:

SELECT ... blah ... blah ... blah ...
FROM SomeTable
WHERE SomeColumn = @Param1
SELECT @intRowCount = @@ROWCOUNT, @intErrNo = @@ERROR

IF @debug = 1 THEN SELECT [MySprocName] = 'DEBUG(1)', [@intRowCount]=@intRowCount, [@intErrNo]=@intErrNo, [@Param1]=@Param1

which requires finding where the "DEBUG(1)" label is to see what the RowCount is referring to, but typically I am reading the code, and checking the associated DEBUG(nnn) statement in the resultset to see what the appropriate values were, which seems to work for us. I would probably then add some more debugging SELECT statements, or append more variables to the existing ones, and run the Sproc again until I had the debugging data I needed to figure out what the problem was.

If you will be needing to post-mortem examine the logging results (perhaps because the SProc takes a long time to run, or doesn't always fail) then outputting to a Logging Table would work well.

We have a single, generic, error logging table which we use for that purpose:

varchar - NAME - e.g. of the Sproc / script being run
INT - Error / Result Code value
varchar - Message - some relevant message / indicator of location within the code
varchar - Optional Values 1 to 5 - allows for output of up to 5 values. We sometimes concatenate values together to store in one the columns, e.g.

INSERT INTO MyLogTable
SELECT 'MySprocName', 1, 'DEBUG(1)', '@intRowCount=' + CONVERT(varchar(20), @intRowCount)
    + ', @intErrNo=' + CONVERT(varchar(20), @intErrNo)
    + ', @Param1=' + COALESCE(@Param1, 'NULL'),
    ....

#3

@Kristen No NOLOCK in the proc anywhere.

I like the debugging on all SP's idea, but that'll be a pretty massive project in our case.

I ended up building a table and adding a column for every parameter value pre and post, cursor values, fetch values and some other debugging inserts throughout the procedure and re-ran it and was able to pinpoint the location of the issue, but now I'll have to figure out why it skipped one record. At least I know which step it failed at and that step has a suspiciously complicated multiple self joining where not exists clause so should be able to track it down.

Sample Debug statements sprinkled throughout code (ended up with 39 debugs going into a table with 57 columns)

/DEBUG3/ INSERT INTO SPDebugTable(DebugNum,CursorValueID) VALUES(3,@ID)
/DEBUG4/ INSERT INTO SPDebugTable(DebugNum,PreCursorFetch) VALUES(4,@@FETCH_STATUS)
WHILE (@@FETCH_STATUS = 0)
/DEBUG5/ INSERT INTO SPDebugTable(DebugNum,CursorValueID) VALUES(5,@ID)
/DEBUG6/ INSERT INTO SPDebugTable(DebugNum,PostCursorFetch) VALUES(6,@@FETCH_STATUS)

IF (@U >= @O)
BEGIN
/DEBUG28/ INSERT INTO SPDebugTable(DebugNum,IFUGorEO) VALUES(28,'Yes')


#4

Looks good to me :slight_smile:

Have you thought about how to remove the DEBUGs when you are done? Maybe you will just "port" the code-fix to the original, but then the DEBUGs will not be there for next time (hence our IF @debug=1 THEN ... so we can leave them in the code - that would work even with a local-variable, initialised to ZERO when you have finished debugging).

The other thing we do is:

/**DEBUG*
... some debug code here ...
*DEBUG**/

and we use the single/double "*" as indicators of what to comment-in / comment-out (and use a programmers-editor with RegEd Replace etc. to find-and-fix them. When debugging that same code would be changed to:

/**DEBUG*/
... some debug code here ...
/*DEBUG**/