Click here to monitor SSC
SQLServerCentral is supported by Red Gate Software Ltd.
 
Log in  ::  Register  ::  Not logged in
 
 
 
        
Home       Members    Calendar    Who's On


Add to briefcase ««12

Re-throw Errors with Logging Expand / Collapse
Author
Message
Posted Thursday, March 28, 2013 1:20 PM
Valued Member

Valued MemberValued MemberValued MemberValued MemberValued MemberValued MemberValued MemberValued Member

Group: General Forum Members
Last Login: Tuesday, October 7, 2014 12:10 PM
Points: 55, Visits: 436
The fundamental problem with writing an error to a log within a transaction that is subsequently rolled back is that everything written by the connection within the transaction is rolled back--including the error message.

So the only solution is to either wait until after the end of the transaction (i.e. perform the ROLLBACK and then log the error), or to use a different connection that is not part of the transaction.

One way to use a different transaction is to use CLR (as steven.bingham posted).

Another is to use ADO, called from within a T-SQL procedure.

Here is an example of this approach being used:
BEGIN TRAN
BEGIN TRY
RAISERROR('Sample Error for Testing', 16, 1)
COMMIT TRAN
END TRY
BEGIN CATCH
DECLARE @ThisMsg varchar(MAX)
SET @ThisMsg = 'We had an error: ' + ERROR_MESSAGE()
EXEC dbo.spLogErrorCommitted @Msg = @ThisMsg
ROLLBACK TRAN
END CATCH

SELECT * FROM dbo.tblErrorLog

The message will remain in dbo.tblErrorLog even though the transaction was rolled back.


I'm happy to provide the declaration of dbo.spLogErrorCommitted if anyone is interested. But the basic idea is that it uses ADO (via sp_OACreate) to establish a new database connection and to perform the insert into the log table.

In this way the inserted error log row is not removed when the transaction is rolled back.
Post #1436686
Posted Thursday, March 28, 2013 1:38 PM
Grasshopper

GrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopper

Group: General Forum Members
Last Login: Tuesday, September 23, 2014 1:05 AM
Points: 22, Visits: 169
David, I'm certainly intrested to see the declaration of that SP.

Has anyone measured the performance cost of either of these techniques (Steve's CLR using a seperate transaction context and David's approach to use ADO) ?
This probably won't be that critical if they are restricted to pure exception handling, but it's another situation if this would be used for more general logging purposes.
Post #1436701
Posted Thursday, March 28, 2013 2:32 PM
Valued Member

Valued MemberValued MemberValued MemberValued MemberValued MemberValued MemberValued MemberValued Member

Group: General Forum Members
Last Login: Tuesday, October 7, 2014 12:10 PM
Points: 55, Visits: 436
I haven't measured performance for this specific routine, but I have compared performance between CLR and COM calls in the past (i.e. for retrieving HTML from a remote server).

CLR is faster--and is the preferred approach suggested by Microsoft and most developers.

COM is simpler to deploy, and performs adequately for many things. With COM you can use pure T-SQL code, and don't need to register any assemblies on the server.

To illustrate the performance difference: a certain procedure using COM can execute 200 times in 22 seconds. The same procedure written using CLR can execute 200 times in 13 seconds.

So CLR is definitely faster and "better"...once it is written and deployed. Using COM is simpler to write and deploy if you prefer working in T-SQL and are not in the business of writing C# code and deploying .NET assemblies and CLR stored procedures.

Post #1436739
Posted Thursday, March 28, 2013 4:08 PM
Forum Newbie

Forum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum Newbie

Group: General Forum Members
Last Login: Friday, September 12, 2014 6:47 PM
Points: 4, Visits: 74
As the saying goes "There's more than one way to skin a cat".

I too would like to see the declaration of dbo.spLogErrorCommitted. The nice thing about
the ADO approach is it's relative simplicity. Although, there are the execute permission considerations in leveraging the sp_OACreate, which if memory serves me correctly is an extended stored proc.

There are also some configuration considerations with the CLR stored proc. approach. Some functionality in this CLR stored proc. requires it to have an assembly permission option of 'EXTERNAL_ACCESS'. With this permission option you will also either have to sign your assembly with a key OR set the database 'Trustworthy' setting to true. Either way you'll want
your DBA's blessing.

The best approach is the one that works best for you!

As for the performance issue, CLR objects often aren't that bad for performance. In this case given the nature of exceptions you likely won't be running this often or frequent enough for performance to be an issue.
Post #1436779
Posted Thursday, March 28, 2013 4:43 PM
Valued Member

Valued MemberValued MemberValued MemberValued MemberValued MemberValued MemberValued MemberValued Member

Group: General Forum Members
Last Login: Tuesday, October 7, 2014 12:10 PM
Points: 55, Visits: 436
Here is a script that demonstrates an ADO-based approach for logging within a transaction that may later be rolled back.

This script creates dbo.spLogErrorCommitted and other needed objects, and prints out some instructions.

/*
Script to create an error logging procedure that can record errors
that will retain the error messages even when they were written within
a transaction that is subsequently rolled back.

Written by David Rueter (drueter@assyst.com) 3/28/2013
Not copyrighted / Public domain / Use at your own risk.
*/

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO

/*
To remove objects created by this script:

DROP PROCEDURE dbo.spLogErrorCommitted
DROP PROCEDURE dbo.spLogError
DROP TABLE dbo.tblErrorLog
DROP USER errorWriter
DROP LOGIN errorWriter
*/


/*
Create a table to hold error log messages.
*/
CREATE TABLE tblErrorLog (
ErrorLogID int IDENTITY PRIMARY KEY,
DateLogged datetime DEFAULT (GETDATE()),
Msg varchar(MAX)
)

GO

/*
Create a procedure to insert errror messages into the log table
*/
CREATE PROCEDURE dbo.spLogError
@Msg varchar(MAX)
AS
BEGIN
SET NOCOUNT ON
INSERT INTO tblErrorLog (Msg) VALUES (@Msg)
END

GO

/*
Create a new SQL login for ADO to use to call back into the database. This user will ONLY have rights to execute the dbo.spLogError procedure.'
*/
DECLARE @SQL varchar(MAX)
SET @SQL = 'CREATE LOGIN errorWriter WITH PASSWORD=N''errorWriterPW'', DEFAULT_DATABASE=[' + DB_NAME() + '], DEFAULT_LANGUAGE=[us_english], CHECK_EXPIRATION=OFF, CHECK_POLICY=OFF'
EXEC(@SQL)

/*
Create a new SQL user in the current database linked to the new login created above.
*/
CREATE USER [errorWriter] FOR LOGIN [errorWriter] WITH DEFAULT_SCHEMA=[dbo]

GO


/*
Grant rights to the new errorWriter user to execute the dbo.spLogError procedure
*/
GRANT EXEC ON dbo.spLogError TO errorWriter

GO

/*
Create the procedure that will be called to log and commit an error message even inside
a transaction that will be rolled back.
*/

CREATE PROCEDURE dbo.spLogErrorCommitted
@Msg varchar(MAX),
@SuppressInternalErrors bit = 0
AS
BEGIN
/*
This procedure is designed to allow a caller to provide a message that will be written to an error log table,
and allow the caller to call it within a transaction. The provided message will be persisted to the
error log table even if the transaction is rolled back.

To accomplish this, this procedure utilizes ADO to establish a second database connection (outside
the transaction context) back into the database to call the dbo.spLogError procedure.
*/

SET NOCOUNT ON

DECLARE @ConnStr varchar(MAX)
--connection string for ADO to use to access the database
SET @ConnStr = 'Provider=SQLNCLI10; DataTypeCompatibility=80; Server=localhost; Database=' + DB_NAME() + '; Uid=errorWriter; Pwd=errorWriterPW;'

DECLARE @SQLCommand varchar(MAX)
SET @SQLCommand = 'EXEC dbo.spLogError @Msg=''' + REPLACE(@Msg, CHAR(39), CHAR(39) + CHAR(39)) + ''''

DECLARE @ObjCn int
--ADO Connection object
DECLARE @ObjRS int
--ADO Recordset object returned

DECLARE @RecordCount int
--Maximum records to be returned
SET @RecordCount = 0

DECLARE @ExecOptions int
--Execute options: 0x80 means to return no records (adExecuteNoRecords) + 0x01 means CommandText is to be evaluted as text
SET @ExecOptions = 0x81

DECLARE @LastResultCode int = NULL
--Last result code returned by an sp_OAxxx procedure. Will be 0 unless an error code was encountered.
DECLARE @ErrSource varchar(512)
--Returned if a COM error is encounterd
DECLARE @ErrMsg varchar(512)
--Returned if a COM error is encountered

DECLARE @ErrorMessage varchar(MAX) = NULL
--our formatted error message


SET @ErrorMessage = NULL
SET @LastResultCode = 0


BEGIN TRY
EXEC @LastResultCode = sp_OACreate 'ADODB.Connection', @ObjCn OUT
IF @LastResultCode <> 0 BEGIN
EXEC sp_OAGetErrorInfo @ObjCn, @ErrSource OUTPUT, @ErrMsg OUTPUT
END
END TRY
BEGIN CATCH
SET @ErrorMessage = ERROR_MESSAGE()
END CATCH


BEGIN TRY
IF @LastResultCode = 0 BEGIN

EXEC @LastResultCode = sp_OAMethod @ObjCn, 'Open', NULL, @ConnStr
IF @LastResultCode <> 0 BEGIN
EXEC sp_OAGetErrorInfo @ObjCn, @ErrSource OUTPUT, @ErrMsg OUTPUT
END
END
END TRY
BEGIN CATCH
SET @ErrorMessage = ERROR_MESSAGE()
END CATCH


IF @LastResultCode = 0 BEGIN
EXEC @LastResultCode = sp_OAMethod @ObjCn, 'Execute', @ObjRS OUTPUT, @SQLCommand, @RecordCount, @ExecOptions
IF @LastResultCode <> 0 BEGIN
EXEC sp_OAGetErrorInfo @ObjCn, @ErrSource OUTPUT, @ErrMsg OUTPUT
END
END

IF @ObjRS IS NOT NULL BEGIN
BEGIN TRY
EXEC sp_OADestroy @ObjCn
END TRY
BEGIN CATCH
--not much we can do...
SET @LastResultCode = 0
END CATCH
END

IF @ObjCn= 1 BEGIN
BEGIN TRY
EXEC sp_OADestroy @ObjCn
END TRY
BEGIN CATCH
--not much we can do...
SET @LastResultCode = 0
END CATCH
END

IF (@SuppressInternalErrors = 1) AND ((@LastResultCode <> 0) OR (@ErrorMessage IS NOT NULL)) BEGIN
SET @ErrorMessage = 'Error in spLogErrorCommitted' + ISNULL(': ' + @ErrMsg, '')
RAISERROR(@ErrorMessage, 16, 1)
--We are in an error-logging routine. If the we encounter an error here, there's not a lot we can do.
--Don't raise an error or try to log this internal error.
END

END

GO

DECLARE @CRLF varchar(5)
SET @CRLF = CHAR(13) + CHAR(10)

DECLARE @Instructions varchar(MAX)

SET @Instructions =
'You can now call dbo.spLogErrorCommitted to write error messages to dbo.tblErrorLog.' + @CRLF +
'Messages written via this procedure will be retained even if written within a transaction' + @CRLF +
'that is rolled back.' + @CRLF +
@CRLF +
'To demonstrate that this works, try executing the following:' + @CRLF +
'
BEGIN TRAN
BEGIN TRY
RAISERROR(''Sample Error for Testing'', 16, 1)
COMMIT TRAN
END TRY
BEGIN CATCH
DECLARE @ThisMsg varchar(MAX)
SET @ThisMsg = ''We had an error: '' + ERROR_MESSAGE()
EXEC dbo.spLogErrorCommitted @Msg = @ThisMsg
ROLLBACK TRAN
END CATCH

SELECT * FROM dbo.tblErrorLog' + @CRLF +
@CRLF +
'Note that the row still exists in dbo.tblErrorLog, even though ROLLBACK TRAN was called' + @CRLF +
'after the message was inserted into a row in the table.' + @CRLF +
@CRLF +
'Remember that this stored procedure uses OLE. To work properly you may need to configure ' +
'your database to allow OLE, as follows: ' + @CRLF +
' EXEC sp_configure ''show advanced options'', 1;' + @CRLF +
' RECONFIGURE;' + @CRLF +
' EXEC sp_configure ''Ole Automation Procedures'', 1;' + @CRLF +
' RECONFIGURE;' + @CRLF +
'Also, your SQL user must have execute rights to the following stored procedures in master:' + @CRLF +
' sp_OACreate' + @CRLF +
' sp_OAGetProperty' + @CRLF +
' sp_OASetProperty' + @CRLF +
' sp_OAMethod' + @CRLF +
' sp_OAGetErrorInfo' + @CRLF +
' sp_OADestroy' + @CRLF +
'You can grant rights for each of these as follows:' + @CRLF +
' USE master' + @CRLF +
' GRANT EXEC ON sp_OACreate TO myuser' + @CRLF +
' GRANT EXEC etc. ...' + @CRLF

PRINT @Instructions

Post #1436787
Posted Monday, April 1, 2013 10:51 PM
SSC-Addicted

SSC-AddictedSSC-AddictedSSC-AddictedSSC-AddictedSSC-AddictedSSC-AddictedSSC-AddictedSSC-Addicted

Group: General Forum Members
Last Login: Friday, October 17, 2014 7:55 AM
Points: 411, Visits: 1,406
Phil Factor wrote a nice article about error handling when transactions are involved here. The only thing I had to add to it, is already in the comments below the article.



Posting Data Etiquette - Jeff Moden
Posting Performance Based Questions - Gail Shaw
Hidden RBAR - Jeff Moden
Cross Tabs and Pivots - Jeff Moden
Catch-all queries - Gail Shaw


If you don't have time to do it right, when will you have time to do it over?
Post #1437690
« Prev Topic | Next Topic »

Add to briefcase ««12

Permissions Expand / Collapse