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 Wednesday, March 27, 2013 10:15 PM
Forum Newbie

Forum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum Newbie

Group: General Forum Members
Last Login: Thursday, January 16, 2014 2:48 PM
Points: 9, Visits: 435
Comments posted to this topic are about the item Re-throw Errors with Logging
Post #1436257
Posted Thursday, March 28, 2013 2:12 AM
Grasshopper

GrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopper

Group: General Forum Members
Last Login: Monday, July 28, 2014 3:56 AM
Points: 22, Visits: 163
Hi, thank you for this article. What would be the best technique to have exception logging beyond a begin tran...rollback scenario, the problem being that any error logged to a table is also rolled back when you rollback a transaction, so again no trace of the exception...

thanks

Dirk.
Post #1436301
Posted Thursday, March 28, 2013 5:50 AM
Grasshopper

GrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopper

Group: General Forum Members
Last Login: Monday, July 21, 2014 11:31 AM
Points: 17, Visits: 36
Exactly my thoughts, Dirk. This solution doesn't work with rolled back transactions. The only way we have found is to use cmdshell to log errors in local txt file on the server.
Additionally you can have some job which would upload that file back to the database, but we didn't go that far.
You can get fancy and save errors not just as plain txt, but as csv or even xml form, depending on your needs.
Does anybody have better idea?
Post #1436412
Posted Thursday, March 28, 2013 6:49 AM
SSCrazy

SSCrazySSCrazySSCrazySSCrazySSCrazySSCrazySSCrazySSCrazy

Group: General Forum Members
Last Login: 2 days ago @ 1:03 PM
Points: 2,445, Visits: 1,316
If you are using transactions, you can put the rollback statement at the beginning of the catch as follows:
BEGIN CATCH;
ROLLBACK;
SET @Result = 0;
-- re-raise the error to be caught in the calling process
EXECUTE @Result = dbo.pReThrowErrorwithlogging @ProcedureName = @SPName, @logError = 1, @Debug = 1;
END CATCH;

That will allow the procedure to log the error.
Post #1436445
Posted Thursday, March 28, 2013 7:11 AM
Forum Newbie

Forum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum Newbie

Group: General Forum Members
Last Login: Thursday, February 6, 2014 6:07 AM
Points: 2, Visits: 14
A couple of suggestions.

Incorporate Granularity: Log4Net and nLog and others have the concept of logging levels viz Trace / Debug / Info / Warn / Severe / Fatal.

Any exception should have a granularity IMHO and be handled accordingly.

This leads to:

Standardize Exception Objects: Every exception ought to be in a registry of some sort with an ID, Severity, Message, etc. and possibly redress actions. THose are independent of the application(s) themselves, so they can be reused across a suite of apps.

Finally:

as far as I can see, this does not capture anything about the server instance(in cluster). thread or session that generated the problem which may be critical. A function should be incorporated that does that and records it along with the exception. This might be done by some sort of 'Job ID' but those may not be unique....
Post #1436451
Posted Thursday, March 28, 2013 7:26 AM
Grasshopper

GrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopperGrasshopper

Group: General Forum Members
Last Login: Monday, July 28, 2014 3:56 AM
Points: 22, Visits: 163
Hi William, In a single stored procedure this will indeed allow you to have a trace of the exception, in real world you often have nested stored procedures, triggers called within the transaction-scope, and all log-records to assist you in trying to analyse the problem/flow are gone too once you've rolled back (but I realize i'm now mixing logging in general and Exception logging).
But your solution is already much better than having no logging at all, and imho also much better that having to fall back to external logfiles. It would be nice to have a statement/keyword to enable you to do DML beyond the scope of the current transaction, however dangerous that may sound
Post #1436458
Posted Thursday, March 28, 2013 7:28 AM
Valued Member

Valued MemberValued MemberValued MemberValued MemberValued MemberValued MemberValued MemberValued Member

Group: General Forum Members
Last Login: Wednesday, June 25, 2014 4:22 PM
Points: 52, Visits: 405
You can log the error to the SQL Server system log by specifying "WITH LOG" on your call to RAISERROR. These log entries survive the transaction rollback:

BEGIN TRAN
BEGIN TRY
RAISERROR('Sample Error for Testing', 16, 1) WITH LOG
COMMIT TRAN
END TRY
BEGIN CATCH
PRINT 'Error message was logged to the SQL Server log even though the transaction has been rolled back.'
ROLLBACK TRAN
END CATCH

(See the log in SSMS under Management / SQL Server Logs / Current)

This doesn't help you log to a normal table...but it may be cleaner than writing to a flat file from xp_cmdshell.
Post #1436461
Posted Thursday, March 28, 2013 8:57 AM
Forum Newbie

Forum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum Newbie

Group: General Forum Members
Last Login: Monday, July 28, 2014 1:28 PM
Points: 4, Visits: 67
Team,

I have an answer for retaining logging errors during a rollback situation.
I have an associated reply to another post that you can read at this link
http://social.msdn.microsoft.com/Forums/en-US/vstsdb/thread/2ab351c2-00cc-4500-841b-35c3271e040b/.

I use a similiar approach of implementing TRY/CATCH statements in my stored
procedures and submitting the errors to a database table via an error logging
stored procedure. However, I use a CLR stored procedure to handle the logging
to deal with the transaction issue. Here are the details...

Often times you can run stored procedures from many processes, like other stored
procedures, where there are different levels of transactions. The problem is that if you
write to your log table and a rollback occurs, you lose that error record. Even if you write
the log record after a rollback statement, you could lose your record if that stored proc.
itself is running with in inner transaction context and the out transaction rolled back.

This is simply handled by creating a CLR Stored Procedure, because with a CLR Stored
Proc. you can create a seperate transaction context, within which to write the record to
the logging table, and that context is not affected any transaction contexts of the T-SQL
stored procs that were running, not matter how deep your levels of transactions.

From within the CLR stored proc. I get the pertainent information about the database
and server and dynamically construct my connection string, which points back to the
database the stored proc. is on. I then create a seperate connection, in a seperate
transaction context, and write a record to the logging table. You should be able to
infer the schema of the table from the code.

In the CATCH section that calls this CLR stored proc., I write an error to the system
event log if an exception is throw by this stored procedure. The stored proc. is generic
enough that I could use it, as is, on any database as long as it has a consistently structure
error logging table.


CODE SAMPLE BELOW

using System;
using System.Data;
using System.Data.SqlClient;
using System.Data.SqlTypes;
using System.Security;
using System.Security.Principal;
using System.Transactions;
using Microsoft.SqlServer.Server;


public partial class LogDatabaseError
{
[Microsoft.SqlServer.Server.SqlProcedure]
public static void usp_clrLogDatabaseError(SqlDateTime ErrorEventDateTime
,SqlInt32 ErrorNumber
,SqlInt32 ErrorSeverity
,SqlInt32 ErrorState
,SqlString ErrorProcedure
,SqlInt32 ErrorLine
,SqlString ErrorMessage)
{
try
{

const string DATASOURCE = "Data Source=";
const string INITIALCATALOG = ";Initial Catalog=";
const string INTEGRATEDSECURITY = ";Integrated Security=True;Enlist=false;";

string dynamicConnString;
string SQL_InstanceName;
string SQL_DatabaseName;

//Establish a connection in the current context to dynamically get the current
//Server and Database Name.
using (SqlConnection sysconn = new SqlConnection("context connection=true"))
{
SqlCommand GetSQLSystemProperties = new SqlCommand();
GetSQLSystemProperties.Connection = sysconn;

sysconn.Open();

//Get the current SQL Server instance name
GetSQLSystemProperties.CommandText = "SELECT @@Servername";
SQL_InstanceName = (string)GetSQLSystemProperties.ExecuteScalar();

//Get the current Database Name
GetSQLSystemProperties.CommandText = "SELECT DB_NAME()";
SQL_DatabaseName = (string)GetSQLSystemProperties.ExecuteScalar();
sysconn.Close();
}

//Dynamically construct the connection string to establish a connection outside
//of the current context, so that any error written to the error table won't be
//rolled back.
dynamicConnString = DATASOURCE + SQL_InstanceName + INITIALCATALOG + SQL_DatabaseName + INTEGRATEDSECURITY;

using (SqlConnection conn = new SqlConnection(dynamicConnString))
{
SqlCommand InsertDatabaseErrorRecord = new SqlCommand();

SqlParameter ErrorEventDateTimeParam = new SqlParameter("@errorEventDateTime", SqlDbType.DateTime);
SqlParameter ErrorNumberParam = new SqlParameter("@errorNumber", SqlDbType.Int);
SqlParameter ErrorSeverityParam = new SqlParameter("@errorSeverity", SqlDbType.Int);
SqlParameter ErrorStateParam = new SqlParameter("@errorState", SqlDbType.Int);
SqlParameter ErrorProcedureParam = new SqlParameter("@errorProcedure", SqlDbType.NVarChar, 200);
SqlParameter ErrorLineParam = new SqlParameter("@errorLine", SqlDbType.Int);
SqlParameter ErrorMessageParam = new SqlParameter("@errorMessage", SqlDbType.NVarChar, 4000);

ErrorEventDateTimeParam.Value = ErrorEventDateTime;
ErrorNumberParam.Value = ErrorNumber;
ErrorSeverityParam.Value = ErrorSeverity;
ErrorStateParam.Value = ErrorState;
ErrorProcedureParam.Value = ErrorProcedure;
ErrorLineParam.Value = ErrorLine;
ErrorMessageParam.Value = ErrorMessage;

InsertDatabaseErrorRecord.Parameters.Add(ErrorEventDateTimeParam);
InsertDatabaseErrorRecord.Parameters.Add(ErrorNumberParam);
InsertDatabaseErrorRecord.Parameters.Add(ErrorSeverityParam);
InsertDatabaseErrorRecord.Parameters.Add(ErrorStateParam);
InsertDatabaseErrorRecord.Parameters.Add(ErrorProcedureParam);
InsertDatabaseErrorRecord.Parameters.Add(ErrorLineParam);
InsertDatabaseErrorRecord.Parameters.Add(ErrorMessageParam);



InsertDatabaseErrorRecord.CommandText =
" INSERT INTO CLIENT.ErrorLog " +
" (ErrorEventDateTime " +
" ,ErrorNumber " +
" ,ErrorSeverity " +
" ,ErrorState " +
" ,ErrorProcedure " +
" ,ErrorLine " +
" ,ErrorMessage) " +
" VALUES " +
" (@errorEventDateTime " +
" ,@errorNumber " +
" ,@errorSeverity " +
" ,@errorState " +
" ,@errorProcedure " +
" ,@errorLine " +
" ,@errorMessage) ";

InsertDatabaseErrorRecord.Connection = conn;
conn.Open();
InsertDatabaseErrorRecord.ExecuteNonQuery();
conn.Close();
}
}
catch (Exception LogException)
{
throw new Exception("The usp_LogDatabaseError error logging routine experienced a problem while attempting to write an error the logging table.", LogException);
}
}
};



I hope this is helpful and happy logging!!
Post #1436531
Posted Thursday, March 28, 2013 10:44 AM
Ten Centuries

Ten CenturiesTen CenturiesTen CenturiesTen CenturiesTen CenturiesTen CenturiesTen CenturiesTen Centuries

Group: General Forum Members
Last Login: Friday, July 25, 2014 11:07 AM
Points: 1,392, Visits: 458
steven.bingham (3/28/2013)
Team,
...
Often times you can run stored procedures from many processes, like other stored
procedures, where there are different levels of transactions. The problem is that if you
write to your log table and a rollback occurs, you lose that error record. Even if you write
the log record after a rollback statement, you could lose your record if that stored proc.
itself is running with in inner transaction context and the out transaction rolled back.
...


This is a common misconception with TSQL. A COMMIT statement commits the innermost transaction, but a ROLLBACK statement rolls back to the outermost transaction. So if you do a rollback, you're no longer inside any nested transactions. (You can explicitly rollback to a savepoint, but when using ROLLBACK by itself or even ROLLBACK @transaction_name, you're always rolling back ALL active transactions.)

Another technique I've seen used is taking advantage of table variables to store errors and relevant details inside of transactions. If you insert data into a table variable and then rollback the transaction, the table variable isn't affected and will still contain the same data as before the rollback. This can be useful for inline debugging, but for logging you still need to make sure the transaction has committed or rolled back before logging from the table var back to a table.
Post #1436613
Posted Thursday, March 28, 2013 12:50 PM
Forum Newbie

Forum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum NewbieForum Newbie

Group: General Forum Members
Last Login: Monday, July 28, 2014 1:28 PM
Points: 4, Visits: 67
NBSteve,

I'm not exactly sure what you were referring too was a misconception, but my intent
wasn't to explain all the nuances of transaction commits and rollbacks.

I'm familiar with people trying to use savepoints and the like and using variables is
one approach and I've heard of several other approachs people have suggested to
handle the error logging issue where transactions are concerned.

However, my experience has been that using the CLR stored proc. approach is simple, extensible and really, for me at least, has made the transaction issue a non issue.

Transactions can be invoked outside the stored procedure, such as with a C# application or an SSIS package. This is what I meant when I said 'you can run stored procs from many different processes'. Still, the CLR approach has made the transaction issue for logging irrelavent.

Steve
Post #1436676
« Prev Topic | Next Topic »

Add to briefcase 12»»

Permissions Expand / Collapse