Getting sp_tracegenerateevent to work in a stored procedure

Question

I'm having a hard-time debugging a stored procedure called from BizTalk.

In a prior thread, someone suggested using sp_trace_generateevent. [Use SQL Debugger when stored proc called by an external process

Since I need to display a variable, I came up with the following, and it works, I can see the value in SQL Profiler (with EventClass=UserConfigurable:0"

Declare @message nvarchar(128)
Set @message = 'Hello World 2 ' 
exec sp_trace_generateevent @event_class=82, @userinfo = @message 

But when I put it in a "BEGIN CATCH" in the problem stored proc, I don't see anything in the profiler:

BEGIN CATCH 
   DECLARE @message nvarchar(128)
   SET @message = LTRIM(STR(ERROR_MESSAGE())) 
   exec sp_trace_generateevent @event_class=82, @userinfo = @message 
   SET @CatchErrors = 
            'Catch: [LTL].[CreateShipment]  - ErrorNumber: '+LTRIM(STR(ERROR_NUMBER()))
            + ' ErrorSeverity: '+LTRIM(STR(ERROR_SEVERITY()))
            + ' ErrorState: '+LTRIM(STR(ERROR_STATE()))
            + ' ErrorProcedure: '+LTRIM(STR(ERROR_PROCEDURE()))
            + ' ErrorLine: '+LTRIM(STR(ERROR_LINE()))
            + ' ErrorMessage: '+LTRIM(STR(ERROR_MESSAGE()))

END CATCH

So then I put a Catch within the Catch:

BEGIN CATCH 
   BEGIN TRY 
      DECLARE @message nvarchar(128)
      SET @message = LTRIM(STR(ERROR_MESSAGE())) 
      exec sp_trace_generateevent @event_class=82, @userinfo = @message 
   END TRY 
   BEGIN CATCH 
      SET @Message = 'Error in sp_trace_generateevent' 
   END CATCH 
   SET @CatchErrors = 
            'Catch: [LTL].[CreateShipment]  - ErrorNumber: '+LTRIM(STR(ERROR_NUMBER()))
            + ' ErrorSeverity: '+LTRIM(STR(ERROR_SEVERITY()))
            + ' ErrorState: '+LTRIM(STR(ERROR_STATE()))
            + ' ErrorProcedure: '+LTRIM(STR(ERROR_PROCEDURE()))
            + ' ErrorLine: '+LTRIM(STR(ERROR_LINE()))
            + ' ErrorMessage: '+LTRIM(STR(ERROR_MESSAGE()))


END CATCH

And now I can see "SET @Message = 'Error in sp_trace_generateevent' " in the profiler, but I really need to see the reason for the error.

The problem I've having cannot be reproduced when testing in SSMS, only when I call from BizTalk. My intent is to bubble the @CatchErrors (as an output parameter) back to BizTalk, but it's not working either.

Also - BizTalk is running with a user that has SQL SysAdmin (it's on my development machine).

Also same result when using master..sp_tracegeneratedevent

Based on @Jeroen's reply, I switched to this, but still getting some error caught.

   DECLARE @message nvarchar(128)
   BEGIN TRY 
      SET @message = Convert(nvarchar(128),SUBSTRING(ERROR_MESSAGE(),1,128))
      exec sp_trace_generateevent @event_class=82, @userinfo=@message 
   END TRY 

Update #1: This is driving me batty. When I test in SQL it works, but when I test from BizTalk it doesn't. So I really want a debug feature. I now have catch on my catches on my catches... and they are all catching and I don't know why. Same code works fine in the divide by zero simple example. To further complicate, this is a stored proc, called by a stored proc, called by BizTalk. If I catch the error, I should be able to return it to BizTalk in the output parameter called @CatchErrors in my main and sub-stored proc.

BEGIN CATCH 
   DECLARE @message nvarchar(128)
   BEGIN TRY 
      SET @message = Convert(nvarchar(128),SUBSTRING(ERROR_MESSAGE(),1,128))
      exec sp_trace_generateevent @event_class=82, @userinfo=@message 
   END TRY 
   BEGIN CATCH 
      SET @Message = 'Error in sp_trace_generateevent' 
   END CATCH 

   BEGIN TRY 
       SET @CatchErrors = 
            'Catch: [RG].[CreateShipment]  - ErrorNumber: '+CAST(ERROR_NUMBER() AS VARCHAR(35)) 
            + ' ErrorSeverity: '+CAST(ERROR_SEVERITY() AS VARCHAR(35))
            + ' ErrorState: '+CAST(ERROR_STATE() AS VARCHAR(35)) 
            + ' ErrorProcedure: '+CAST(IsNull(ERROR_PROCEDURE(),'') AS VARCHAR(200)) 
            + ' ErrorLine: '+CAST(ERROR_LINE() AS VARCHAR(35)) 
            + ' ErrorMessage: '+CAST(ERROR_MESSAGE() AS VARCHAR(4000)) 
   END TRY 
   BEGIN CATCH 
      BEGIN TRY 
          SET @Message = 'Error in Set @CatchErrors=' 
          SET @CatchErrors = 
                'Catch: [LTL.CreateShipmentStopLineItem]- Error: ' + CAST(ERROR_MESSAGE() AS VARCHAR(4000)) 
      END TRY 
      BEGIN CATCH 
         SET @Message = 'Error in Set @CatchErrors2' 
      END CATCH 
   END CATCH 
END CATCH

Current Profiler Result:

Update #2 - Testing in SSMS:

I'm testing in SSMS, and none of the catches have issues. If i run this more than once it gets Violation of Primary Key in the Print statement.

 Declare @shipstopline LTL.TT_ShipmentStopLineItem
 DECLARE @messageID bigint
 DECLARE @CatchErrorsResult varchar(max) 
 insert into @shipstopline values ('2', '1', 'Eggs','1','2','3','1','100','1','12','1','1','1','10','20','1')

 EXEC LTL.CreateShipmentStopLineItem @MessageId = 2, @ShipmentStopID=1, @CreateBy=108004, @ShipmentStopLineItem=@shipstopline, @loopid=1, @catchErrors=@CatchErrorsResult OUT 
 select RowCreated, * from LTL.ShipmentStopLineItem order by LTL.ShipmentStopLineItem.RowCreated desc
 print @CatchErrorsResult

Answer 1

Well, if you try this:

SET XACT_ABORT ON;
BEGIN TRY   
    SELECT 1 / 0;
END TRY
BEGIN CATCH
    DECLARE @message nvarchar(128);
    SET @message = LTRIM(STR(ERROR_MESSAGE()));
    exec sp_trace_generateevent @event_class=82, @userinfo = @message
END CATCH

You'll get immediate feedback on what's wrong:

Msg 8114, Level 16, State 5, Line 8 Error converting data type nvarchar to float.

And that's because that STR() call you've got is not the right thing to use -- STR formats floating-point values, and only those. (For flexible conversion, use FORMAT and/or CONCAT, the latter of which always implicitly converts things to strings without complaining.)

Aside from that, the first parameter of the stored procedure is @eventid, not @event_class (this is normally an error, but extended stored procedures are more flexible that way -- you could call the parameter @banana and it will still work). Still, for clarity's sake we should use the documented name. So:

SET XACT_ABORT ON;
BEGIN TRY   
    SELECT 1 / 0;
END TRY
BEGIN CATCH
    DECLARE @message nvarchar(128) = ERROR_MESSAGE();
    EXEC sp_trace_generateevent @eventid=82, @userinfo = @message;
END CATCH

And in my profiler, this produces a UserConfigurable:0 event with

Divide by zero error encountered.

Note that if there is no TRY / CATCH, you should still be able to get errors even without generating your own trace event, through the Exception event.

Answer 2

It turns out that BizTalk calls the Stored Proc twice, once with FmtOnly=On and once again with FmtOnly=Off. I was getting the invalid cast exception after the first call, so the Stored Proc was essentially not really executing. I was mislead by the profiler because of the FmtOnly=On, thinking that it was actually executing the statements I saw there. Thus the sp_TraceGenerateEvent doesn't actually run on the first pass with FmtOnly=On, but later when I got past the other errors, it works fine in the second pass with FmtOnly=Off.

Reference: Similar questoin I posted about why the SQL Profiler was looking different between an SSMS run and a BizTalk run of same stored proc: Can SQL Begin Try/Catch be lying to me (in the profiler)?