I’ve been developing and using a simple logging framework for SQL Server on nearly every project I’ve worked on for the last five years, always with the intention of making it available for public use. That framework is Log4TSql and this month’s T-SQL Tuesday finally prompted me to put together a proper build on Sourceforge. This month’s topic is procedures and functions so I thought I would talk a little about one of the procedures in Log4TSql. I’ve found this really useful and hope that you will too.
One of the great features to be introduced in SQL 2005 was the TRY… CATCH… block. But writing all that exception handling code over and over again prompted me to try and encapsulate it in a way that allowed me to write as little code as possible. Enter Log4TSql’s ExceptionHandler, which in a nutshell, is designed to be called within a CATCH block and captures all the available information about an exception. It persists this in a table and also makes all those values available to the caller as output parameters. Finally, it also allows the developer to specify an error context which is persisted along with the rest of the error details.
So as a starting point, here is a slightly scaled down version of the Exception table and the ExceptionHandler procedure. The complete source code for this post alone can be downloaded here. The full version operates in exactly the way I’m describing here but collects some additional information. Log4TSql also has an ExceptionReader but I don’t plan to cover that here. The code below can be used stand alone or you can download the complete framework from Log4TSql at Sourceforge.
IF OBJECTPROPERTY(OBJECT_ID(N'[Exception]'), N'IsUserTable') = 1 DROP TABLE [Exception] GO CREATE TABLE [Exception] ( [ExceptionId] int NOT NULL IDENTITY( 1,1 ) , [UtcDate] datetime NOT NULL , [SystemDate] datetime NOT NULL ----------------------------------------------------------------------- , [ErrorContext] nvarchar ( 512 ) NOT NULL , [ErrorNumber] int NOT NULL , [ErrorSeverity] int NOT NULL , [ErrorState] int NOT NULL , [ErrorProcedure] nvarchar ( 128 ) NOT NULL , [ErrorLine] int NOT NULL , [ErrorMessage] nvarchar ( max ) NOT NULL , PRIMARY KEY ([ExceptionId]) ) GO ALTER TABLE [Exception] ADD CONSTRAINT [DF_Exception_SystemDate] DEFAULT GETDATE() FOR [SystemDate]; ALTER TABLE [Exception] ADD CONSTRAINT [DF_Exception_UtcDate] DEFAULT GETUTCDATE() FOR [UtcDate];
IF OBJECTPROPERTY(OBJECT_ID(N'[ExceptionHandler]'), N'IsProcedure') = 1 DROP PROCEDURE [ExceptionHandler]; GO CREATE PROCEDURE [ExceptionHandler] ( @ErrorContext nvarchar ( 512 ) = NULL , @DatabaseName nvarchar ( 128 ) = NULL OUT , @ErrorProcedure nvarchar ( 128 ) = NULL OUT , @ErrorNumber int = NULL OUT , @ErrorSeverity int = NULL OUT , @ErrorState int = NULL OUT , @ErrorLine int = NULL OUT , @ErrorMessage nvarchar ( 4000 ) = NULL OUT , @ReturnMessage nvarchar ( 1000 ) = NULL OUT , @ExceptionId int = NULL OUT ) AS BEGIN SET NOCOUNT ON; --! Make sure don't have any NULLs SET @ErrorContext = COALESCE(@ErrorContext, '') SET @DatabaseName = COALESCE(@DatabaseName, DB_NAME()) SET @ErrorProcedure = COALESCE(NULLIF(@ErrorProcedure, ''), ERROR_PROCEDURE(), '') SET @ErrorNumber = COALESCE(ERROR_NUMBER(), 0) SET @ErrorSeverity = COALESCE(ERROR_SEVERITY(), 0) SET @ErrorState = COALESCE(ERROR_STATE(), 0) SET @ErrorLine = COALESCE(ERROR_LINE(), 0) SET @ErrorMessage = COALESCE(ERROR_MESSAGE() , 'ERROR_MESSAGE() Not Found for @@ERROR: ' + COALESCE(CAST(ERROR_NUMBER() AS varchar(16)), 'NULL')) --! Generate a detailed, nicely formatted error message to return to the caller DECLARE @context nvarchar(512); SET @context = COALESCE(NULLIF(@ErrorContext, '') + ' due to ', 'ERROR! ') SET @ReturnMessage = @context + CASE WHEN LEN(ERROR_MESSAGE()) > (994 - LEN(@context)) THEN '"' + SUBSTRING(@ErrorMessage, 1, (994 - LEN(@context))) + '..."' ELSE '"' + @ErrorMessage + '"' END; --! Working variables DECLARE @tblExceptionId table (ExceptionId int NOT NULL UNIQUE); --! Record what we have INSERT [Exception] ( [ErrorContext] , [ErrorNumber] , [ErrorSeverity] , [ErrorState] , [ErrorProcedure] , [ErrorLine] , [ErrorMessage] ) OUTPUT inserted.ExceptionId INTO @tblExceptionId VALUES ( @ErrorContext , @ErrorNumber , @ErrorSeverity , @ErrorState , @ErrorProcedure , @ErrorLine , @ErrorMessage ); SELECT @ExceptionId = ExceptionId FROM @tblExceptionId; SET NOCOUNT OFF; RETURN; END
So let’s start by looking at a really simple scenario. [HOWTO_SimpleExample] accepts a couple of float inputs and has one output. The output value is the result of dividing the first input by the second. Obviously, with a default @devisor of zero, we are going to get an error. Within the CATCH block, we have just two lines of code, first we roll back any open transaction and second we call [ExceptionHandler]. That’s it. Done!
IF OBJECTPROPERTY(OBJECT_ID(N'[HOWTO_SimpleExample]'), N'IsProcedure') = 1 DROP PROCEDURE [HOWTO_SimpleExample]; GO CREATE PROCEDURE [HOWTO_SimpleExample] ( @dividend float = 1.6180339887 , @devisor float = 0 , @result float = NULL OUT ) AS BEGIN --! Make sure that we do actually get an error on divide by zero SET ANSI_WARNINGS ON; SET ARITHABORT ON; BEGIN TRY --! Get the result to output SET @result = @dividend / @devisor; END TRY BEGIN CATCH IF ABS(XACT_STATE()) = 1 OR @@TRANCOUNT > 0 ROLLBACK TRAN; EXEC ExceptionHandler; END CATCH RETURN; END
In this simple example, [HOWTO_SimpleExample] is only doing one thing so there is no need to supply an error context. Also, as we are intentionally hiding the exception, we don’t need to collect any outputs from [ExceptionHandler]. If you were writing a module like this where the exception is hidden from the calling procedure, the caller would be responsible for validating the output and raising any error of it’s own.
If you have already created the [Exception] table and [ExceptionHandler] procedure, create [HOWTO_SimpleExample] and run it like this
SELECT * FROM Exception will show what has been collected.
It’s all well and good persisting the details of the error, but sometimes you want to do more, so lets look at a more detailed example. in [HOWTO_DetailedExample], the business logic is the same but our TRY block has a few more steps and we now have a requirement to throw any error back to the caller.
Different developers have different views on whether a T-SQL TRY…CATCH… block should contain just a single operation or can contain multiple steps. As I don’t like writing lines and lines of near identical code, I prefer to put related steps in the same TRY…CATCH… block and then ensure I can identify the failure step from within the CATCH block. The whole point of Log4TSql exception handling is that you can provide as much or as little information as you, the developer, see fit. In this scenario, as I have multiple steps in my TRY block, I need to make sure that I identify each one using
SET @_Step = so that in the event of an error being raised, I can identify the exact point of failure from within the catch block.
So, when the code runs, if an error is caught, the first thing we do in the CATCH block is capture the context in which the error occurred. You can see that we pick up the current value of @_Step and we have also chosen to capture the more important input parameters (although in this case there are only two). We have to work within the limits of @_ErrorContext maximum length of 512 characters but if you want more logging than this check out Log4TSql’s JournalWriter. Note also that when building @_ErrorContext we always use ISNULL() or COALESCE() to ensure that any unexpected NULLs do not prevent the rest of the info being collected.
IF OBJECTPROPERTY(OBJECT_ID(N'[HOWTO_DetailedExample]'), N'IsProcedure') = 1 DROP PROCEDURE [HOWTO_DetailedExample]; GO CREATE PROCEDURE [HOWTO_DetailedExample] ( @dividend float = 1.6180339887 , @devisor float = 0 , @result float = NULL OUT ) AS BEGIN SET NOCOUNT ON --! Standard/ExceptionHandler variables DECLARE @_Error int , @_Step nvarchar ( 128 ) , @_Message nvarchar ( 512 ) , @_ErrorContext nvarchar ( 512 ) SET @_Error = 0; BEGIN TRY SET @_Step = 'Validate inputs'; IF @dividend IS NULL BEGIN SET @_Message = 'Found invalid Dividend: ' + COALESCE(CAST(@dividend AS varchar(16)), 'NULL'); RAISERROR(@_Message, 16, 1); END IF @devisor IS NULL BEGIN SET @_Message = 'Found invalid Divisor: ' + COALESCE(CAST(@devisor AS varchar(16)), 'NULL'); RAISERROR(@_Message, 16, 2); END SET @_Step = 'Calculate output value'; --! Do the business logic SET @result = @dividend / @devisor; END TRY BEGIN CATCH SET @_ErrorContext = 'Failed to demonstrate detailed exception handling' + ' at step: ' + COALESCE('[' + @_Step + ']', 'NULL') + ' for dividend: ' + COALESCE(CAST(@dividend AS varchar(16)), 'NULL') + ' and devisor: ' + COALESCE(CAST(@devisor AS varchar(16)), 'NULL') IF (XACT_STATE() = -1) -- uncommitable transaction OR (@@TRANCOUNT > 0 AND XACT_STATE() != 1) -- undocumented uncommitable transaction BEGIN ROLLBACK TRAN; SET @_ErrorContext = @_ErrorContext + ' (Forced rolled back of all changes)'; END EXEC ExceptionHandler @ErrorContext = @_ErrorContext , @ErrorNumber = @_Error OUT , @ReturnMessage = @_Message OUT ; END CATCH --///////////////////////////////////////////////////////////////////////////////////////////////// OnComplete: --///////////////////////////////////////////////////////////////////////////////////////////////// --! Finally, throw an exception that will be detected by the caller IF @_Error > 0 RAISERROR(@_Message, 16, 99); SET NOCOUNT OFF; --! Return the value of @@ERROR (which will be zero on success) RETURN (@_Error); END
After collecting the error context, the next thing we do is roll back any open uncommitable transaction. Doing this means that any commitable transaction will be left open for the caller to handle – of course any roll back will also roll back the exception info that we store. This is a design decision that you as the developer will need to make on a case by case basis. One thing to be aware of though is that if we do have an open uncommitable transaction, we cannot do anything that requires writing to the transaction log without first rolling back the uncommitable transaction. Since [ExceptionHandler] adds a row to the Exception table, as an absolute minumum you must roll back any uncommitable transaction before calling [ExceptionHandler].
The final thing we do within the catch block is call [ExceptionHandler]. We pass in the @_ErrorContext string and collect the error number and return message outputs. @ReturnMessage combines the error context and error message like this: ‘Failed to demonstrate detailed exception… due to “Divide by zero error encountered.”‘. If you just want the original ERROR_MESSAGE() value generated by SQL Server, collect the output of @ErrorMessage instead of @ReturnMessage.
The final thing we do in this procedure is check whether there was an error and throw the exception as necessary. So when we run this sproc like this, we get the error below.
SELECT * FROM Exception will show what we have collected all the information required to identify why this procedure failed.
That’s my contribution to T-SQL Tuesday, it may not be clever but I like it’s simplicity. I hope that you find this approach to handling exceptions as useful as I have.
Log4TSql is an open source logging framework for SQL Server 2005+ written by Greg M Lucas on behalf of data-centric solutions ltd and licensed for public use under the GNU Lesser General Public License. You can download the latest version of this library along with all the source code and unit tests from sourceforge. Please feel free to use and modify the library as you wish under the terms of the license. I am always interested in hearing how other people or organisations have put this framework to use.