views:

159

answers:

2

Hi, I have some dynamic sql statement which bombs under certain conditions, so I am trying to debug it. it gets built like so:

declare @sql varchar(4000);
...
select @sql = '<part1>';
...
select @sql = @sql + '<part2>';
...
select @sql = @sql + '<part3>';
...
begin 
execute(@sql);
select @ec__errno = @@error
    if @ec__errno != 0
    begin
    if @@trancount != 0
    begin
    rollback;
    end
return @ec__errno;
end;
... 

As I said, it bombs in a particular iteration of a loop (don't ask me why it is implemented like this, I am just fixing a bug) and I am having a hard time displaying the contents of the string in a watch window. I think I am getting the first 255 characters only. Watching for substring(@sql, 0, 200) results in 'substring(@sql,0,200)' could not be evaluated. Please help. I was hoping to watch substrings from 0 to 199, from 200 to 399 and so on, and then piece this thing together and finally debug it.

I would appreciate pointers from you. Thanks!

+1  A: 

When forced to use dynamic sql in a stored proc, we do the following. add an input variable of debug which is a bit field. If it is 0, the exec statment will proces if it is 1 then you will get a print statement instead. I suggest you do something simliar to debug. Instead of executing, print the results of your SQL or possibly insert the SQl to a table since it seems to be happening in a loop. Then you can look over the sql that was built and see where it went wrong.

Declare debug bit
set debug = 1

...
if debug = 1 Begin     Print @SQL End
Else 
Begin Exec (@sql) End

Alternatively

Create a table called mydynamiccode_logging (with a sql column the same length as the max sql statment, a rundatecolumn and whatever other columns you might find necessary (I'd consider the input variables used to make up the sql statment, the user, the application if more than one uses this piece of code)

Before you run the exec statment run something like this:

insert mydynamiccode_logging (sql, rundate)
values (@sql, getdate()) 

Now you could also add the debug bit field and only log when you have changed it to debug mode or you could always log, depends on the system and how much extra time this takes to do and how slammed the rest of the system is. You don't want to slow prod down significantly by logging.

HLGEM
Ah, very cool! Is there any chance of detecting the environment? Sort of like #if Debug ... #endif, or if __name__ == '__main__' (Python)? I wish to add a print statement before executing the dynamic sql if I am "in Debug" as opposed to "in production". Is there a way to make this work?
Hamish Grubijan
the problem with `PRINT` is capturing it in the production environment, which is critical with hard to reproduce issues.
KM
I wouldn't run print in the production environment. I wouldn't try to debug ever in prod.You could I suppose add code to always send the @ sql to a table (with the input variables and the datetime before running the exec. Then everything you sent is logged automatically and you can look through the table to find the problem when there is an error. You'd have to see how this affects execution time though.
HLGEM
+1  A: 

do something like this, it will only log failures:

BEGIN TRY

    DECLARE @LogString   varchar(max)

    --record input parameters
    SET @LogString='@Param1='+COALESCE(''''+@Param1+'''','null')
                   +@Param2='+COALESCE(''''+@Param2+'''','null')
                   +@ParamDate='+COALESCE(''''+CONVERT(varchar(23),@ParamDate,121)+'''','null')
                   +@ParamInt='+COALESCE(''''+CONVERT(varchar(10),@Paramint)+'''','null')

    --build @SQL_String String here
    --repeat as necessary
    SET @LogString=ISNULL(@LogString)+'; '+.... --every logic twist record what is going on

    EXEC (@SQL_String)

END TRY
BEGIN CATCH

    IF XACT_STATE()!=0
    BEGIN
        ROLLBACK TRANSACTION
    END

    SET @LogString=ISNULL(@LogString,'')+'; '
                 +CASE WHEN ERROR_NUMBER()     IS NOT NULL THEN 'Msg '         +CONVERT(varchar(30),   ERROR_NUMBER()     ) ELSE '' END
                 +CASE WHEN ERROR_SEVERITY()   IS NOT NULL THEN ', Level '     +CONVERT(varchar(30),   ERROR_SEVERITY()   ) ELSE '' END
                 +CASE WHEN ERROR_STATE()      IS NOT NULL THEN ', State '     +CONVERT(varchar(30),   ERROR_STATE()      ) ELSE '' END
                 +CASE WHEN ERROR_PROCEDURE()  IS NOT NULL THEN ', Procedure ' +                       ERROR_PROCEDURE()    ELSE '' END
                 +CASE WHEN ERROR_LINE()       IS NOT NULL THEN ', Line '      +CONVERT(varchar(30),   ERROR_LINE()       ) ELSE '' END
                 +CASE WHEN ERROR_MESSAGE()    IS NOT NULL THEN ', '           +                       ERROR_MESSAGE()      ELSE '' END

    INSERT INTO ErrorLog Values (@SQL_String)
    INSERT INTO ErrorLog Values (@LogString)

    --will echo back the complete original error message for the calling application
    DECLARE @ErrorMessage nvarchar(400), @ErrorNumber int, @ErrorSeverity int, @ErrorState int, @ErrorLine int
    SELECT @ErrorMessage = N'Error %d, Line %d, Message: '+ERROR_MESSAGE(),@ErrorNumber = ERROR_NUMBER(),@ErrorSeverity = ERROR_SEVERITY(),@ErrorState = ERROR_STATE(),@ErrorLine = ERROR_LINE()
    RAISERROR (@ErrorMessage, @ErrorSeverity, @ErrorState, @ErrorNumber,@ErrorLine)

    RETURN 9999

END CATCH
KM
Interesting ... we try to keep sql as fast as possible. What is the impact of this particular modification?
Hamish Grubijan
there would only be a few string concatenations, with INSERTs only on failure. I can't imagine that it would hurt that much. Just include it in the procedure that is bombing, you'll get all the info needed to debug your problem, then you can comment it out.
KM
Slow code is always faster than broken code :)
BradC