Monday, August 15, 2016

What Broke, for Heavens' Sake?!

[Warning: SQL Tech !]
Well, so you're working (like me) with Microsoft's SQL Server and you've got all this code, and every now and then it breaks. Usually because some crazy user did something dumb like put a tick ( ' ) in the middle of a text field, like they've been instructed not to do, or managed to add something like a hidden character, or whatever.
Anyhow, the code breaks, and the carefully crafted error trapping works perfectly, so you know the line of the procedure that it died on, and a fairly generic and opaque description of the problem itself.
However, there are two things that you don't know:
1. the actual piece of data that caused the failure
2. the history of the processing of that data up to the point of failure
Knowing the actual data that caused the failure and be a great help; knowing what happened to it on its way to the point of failure can be even a greater eye-opener, especially if you're working with code that you inherited from someone else now long gone.

The obvious way to handle this problem is to add some logging code to your program. Personally, I maintain programs where the data is usually in the form of messages, even when they arrive batched up in a text file, which move through the systems, undergoing one of a number of sequences of operations, depending on where they've come from, what their content is, and where they're going. Each of these messages is assigned a unique ID to identify it on its journey from receipt to emission.
So, I have a log table with these fields:

IDRecord id in the table
CreatedOnDate record was added
SubjectWhat is happening in general
TextDetailed Info about the situation
TrackingIDID of the message being handled
OriginName of the procedure writing the record
SequenceSequence number of call points in procedure

I also have a stored procedure that accepts the fields it needs (the last 5) and inserts a record into the table.
All well and good so far, until you get to the small matter of transactions. Very wonderful things, transactions, and very helpful. Very nice to use to prevent things that have to be done together getting only part-done. Rolling back a transaction allows you to re-try the whole thing again when you know what's going wrong and have fixed the problem. However, the rollback undoes everything the code has written ... including all the logging, so you never get to find out what it was that went wrong - just that it went wrong !

The Light!
This, of course, is not a whole heap of help, but one day I was reading a book on SQL Server and suddenly part of the description of committing (successfully completing a transaction) turned on a light in my head!

COMMIT TRANSACTION makes all data modifications performed since the start of the transaction a permanent part of the database

So if you roll back the transaction, instead of committing it, everything written is rolled back. That's why the records in the log table vanished with a rollback - that much I already understood.
However, what I didn't cotton on to immediately was the implication of the corollary - that things not actually written out are not deleted.
Actually, it was a few lines into a piece of code before something hit me! Variables don't get rolled back - because they're in memory and not written to disc. And what then hit me was that a Table Variable in SQL Server is a Variable - even though it's very often stored in TempDB (on disc!).

The Implementation
So, to keep my logs that will tell me what happened to cause the rollback, I wrote some code to copy the ones for this message out into a table variable of the same structure as my log table, did the rollback, and then stuffed all those saved records back into the log table.

Et Voilà! On trouve tous les donneés intacte!!

The code is like this:

declare @taLogTable ( [Field List] )
insert into @taLogTable
select * from dbo.LogTable where [specify which records I want]
-- ---------------------
rollback transaction
-- ---------------------
set identity_insert dbo.LogTable on
insert into dbo.LogTable ( [Field List] )
select * from @taLogTable where ID not in (select ID from dbo.LogTable)
set identity_insert dbo.LogTable off

But Wait - There's More
That's fine, but there's a small hiccough coming here.
Part one is that the system runs in two separate databases, and we use synonyms to refer to objects in one database from another. That's perfectly fine: if I need to save logging data that's been logged on another machine but is still part of this transaction, I simply use the appropriate synonyms for the tables involved:

declare @taLogTable ([Field List])
insert into @taLogTable
select * from syn_OtherDB_dbo_LogTable where [specify which records I want]
-- ---------------------
rollback transaction
-- ---------------------
set identity_insert syn_OtherDB_dbo_LogTable on
insert into syn_OtherDB_dbo_LogTable ( [Field List])
select * from @taLogTable where ID not in (select ID from syn_OtherDB_dbo_LogTable)
set identity_insert syn_OtherDB_dbo_LogTable off

So I'm using the synonyms obediently, so if I copy the code to a test database, or somewhere similar, where the name of the other database is OtherDB_Test instead of OtherDB then all will still be ok.

Yeah, well, almost. Close, but no cigar! Synonyms are great in SQL Server except that the set identity_insert command (which allows me to push values into a field which otherwise generates its own automatically) doesn't accept synonyms. So, everything has to be explicit, and therefore there's more more worry and work at the time of deployment in a release when you also have to check that all the set identity_insert statements are pointing to the correct databases!

Victory In The End
There is, of course, a way to fix things to avoid this problem (which, if you're bitten by it, probably happens several months after the release and when you've totally forgotten all about it, because it only ever happens with errors, and they really don't happen all that often.

The way to do it is to use a stored procedure instead of the code after the rollback in order to achieve the same result. You pass in to the procedure the name of the database into whose LogTable the data has to return (I called it @strDatabase here), and also the table variable (@taLogTable). Then the code is like this:

declare @strSQL nvarchar(2000)
set @strSQL = 'SET IDENTITY_INSERT ' + @strDatabase + '.dbo.LogTable ON; '
set @strSQL += 'insert into ' + @strDatabase + '.dbo.LogTable'
set @strSQL += '( [Field List] )'
set @strSQL += 'select * from @taLogTable '
set @strSQL += 'where id not in '
set @strSQL += '(select id from ' + @strDatabase + '.dbo.LogTable); '
set @strSQL += 'SET IDENTITY_INSERT ' + @strDatabase + '.dbo.LogTable OFF; '

There is just one little extra piece of code you'll have to incorporate. 
SQL Server needs a type for each object coming in to a stored procedure, so you have to declare a user type for your table variable. This shouldn't be too much of a hardship, especially if you're using the same structure for all your log tables (a very good idea!). The parameters for that procedure turn out to be like this:
@strDatabase varchar(32),
@taLogTable taLogTable readonly

so not such a problem after all, and helps the programmers coming after you!

Have fun - keep cool!   Food next time!