SQLTeam.com | Weblogs | Forums

Error doesn't seem to be trapped when reading a temporary table after committed transaction


#1

Hi,
I created a stored procedure which loads several tables from a linked database in temporary tables, joins them, filters them, formats columns and finally dumps the result in a new temporary table. Then, the records from the resulting temporary table is saved to a physical table and the stored procedure should return the records that were written to the physical table.
I wrapped everything in a transaction to make sure that nothing would be written to the physical table is something goes wrong.
In order to verify/follow what is going on I added some log messages that are written to another physical table (my log table)
here is the code:

USE [MyDatabase];
GO
SET ANSI_NULLS ON;
GO
SET QUOTED_IDENTIFIER ON;
GO
CREATE PROCEDURE [uspMyStoredProc]
WITH EXEC AS CALLER
AS
BEGIN

--SET NOCOUNT ON added to prevent extra result sets from interfering with SELECT statements.
SET XACT_ABORT, NOCOUNT ON;
    
Declare @ProcName nvarchar(100);
Declare @Guid uniqueidentifier;
SET @ProcName = OBJECT_NAME(@@PROCID);
Set @Guid = NewID();

--Log begin of stored procedure
--------------------------------
exec uspLogAction @ProcName, 'Stored procedure started', null, null, 3, @Guid;

BEGIN TRY
   
    ...

      BEGIN TRANSACTION;
        --Log begin of transaction
        ----------------------------
        exec uspLogAction @ProcName, 'TRANSACTION started', null, null, 3, @Guid;  

        ...        
        -- Loading staff in temporary table
        ...
        ...
  
        -- At this stage, I have a table #Temp
        
        --Save result to physical table and let SQL assign the ID (incremental)
        -----------------------------------------------------------------------------
        insert into tblPhysicalTable (sdProcessDateTime, Processtype, ClientNumber,ClientName)
        Select * from #Temp;
        
        
        ----------------------------------------------------------------------
        -- Reload records written to tblPhysicalTable so that I can get the ID

        INSERT  into #Return
        Select  intID, sdProcessDateTime, ProcessType, ClientNumber, ClientName
        from tblPhysicalTable WITH (NOLOCK)  -- With(NoLock) is mandatory since my transaction hasn't been committed yet !!!
        where sdProcessDateTime = @Now;
        
        --Log that the transaction is about to be committed
        exec uspLogAction @ProcName, 'TRANSACTION about to be committed', null, null, 3, @Guid;  
    
    COMMIT TRANSACTION;
    --Now return changes
    Select @MyMessage=Convert(varchar, count(*)) + ' Records found' from #Return
    exec uspLogAction @ProcName, @MyMessage , null, null, 3, @Guid;

    --This will return the needed records to BizTalk
    Select * From #Return;

    Drop table #Return;

    exec uspLogAction @ProcName, 'Stored procedure complete', null, null, 3, @Guid;
END TRY

BEGIN CATCH
  
  DECLARE @ErrorNumber INT = ERROR_NUMBER();
  DECLARE @ErrorLine INT = ERROR_LINE();
  DECLARE @ErrorMsg nvarchar(MAX) = ERROR_MESSAGE();

  IF @@TRANCOUNT > 0 ROLLBACK TRANSACTION;
  --Log the rollback
  EXEC uspLogAction @ProcName, @ErrorMsg , @ErrorNumber , @ErrorLine , 1, @Guid;  -- I cannot log the error before the rollback otherwise the log is also rolled back
  EXEC uspLogAction @ProcName, 'Transaction has been rolled back', null, null, 2, @Guid;
  
  THROW;
END CATCH
END

So when all goes well, I have 5 messages logged:
'Stored procedure started'
'Transaction started'
'Transaction about to be committed'
'# records found'
'Stored procedure complete'

In 95% of calls, I do get the 5 above messages but in some cases, I only have the 3 first log messages (and less often, I got the 4 first logs.)
Occasionally, (when the linked server is not available or in case of deadlock), I do get errors logged:
'Stored procedure started'
'Error message'
'Transaction has been rolled back'

So it seems that all works fine but I cannot explain what can go wrong in my code between 'Commit Transaction' and End Try.
Even if an error would occur after the transaction is committed, the error should be trapped and I would see it in the logs.
(note that I removed a lot of the code that I believe is not relevant but I didn't remove anything between the end transaction and end try because that is where the issue occurs.)

Can anybody point me to the right direction?
Thank you


#2

Error after COMMIT but before 'Stored procedure complete' and also an error within the CATCH? (such that the CATCH logging does not happen)

You sure? I would have expected you to be able to select data inserted by your own process (within a transaction). NOLOCK opens up the possibility of getting someone else's uncommitted stuff and data missing / duplicated because of page splits at the point-in-time when your SELECT runs

I haven't thought it through carefully, but I would be inclined to do:

DECLARE @OriginalTranCount int = @@TRANCOUNT
...
BEGIN TRANSACTION MyLabel_01
SAVE  TRANSACTION MyLabel_02
...
IF @@TRANCOUNT > @OriginalTranCount
BEGIN
    ROLLBACK TRANSACTION MyLabel_02
    COMMIT TRANSACTION MyLabel_01
END

Change your COMMIT TRANSACTION to include "MyLabel_01" too, so that they are all in sync.

which would also take care of the situation where your procedure was called by something which, itself, had already started a transaction.

Always put a size on varchar, wherever you use it, as the default will catch you out from time to time.

Not sure that is any help with your actual underlying problem though.


#3

Hi Kristen,
Thank you for your answer. I'm no SQL expert so it is always nice to see some best practices.

However, after hours of investigation and headaches it turns out that the system calling the stored procedure (BizTalk) systematically encountered a time out when the logs were incomplete so I think I've tried to find an error when there wasn't any. (well there is an error but external to the stored procedure)

If I have more info, I'll post it. It might help others.
Thank you


#4

Might be worth updating statistics on the indexes etc. in case they are stale (and those stale Stats are then causing the query to use a poor query plan, causing it to take longer than necessary)

I would also put an INDEX on whatever is most appropriate for the queries - even if a temporary band-aid - but remember to remove it later and then properly benchmark which additional indexes, if any, are actually needed.

Hopefully one/both of those will make the query run faster, and prevent it timing out.

If you can increase the BizTalk timeout period that would be a band-aid too!


#5

Just to point out the issue you are encountering...

When you write to any table or temp table inside a transaction - then rollback that transaction - then everything is rolled back. The only way around that is to use a table variable which is not rolled back and write to the physical table outside the transaction.