Error and Transaction Handling in SQL Server

Appendix 2: CLR Modules

An SQL text by Erland Sommarskog, SQL Server MVP Latest revision: 2015-05-03.
Copyright applies to this text. See here for font conventions used in this article.

Introduction

This article is an appendix to the three-part series Error and Transaction Handling in SQL Server. The appendix falls into two halves. The first half is an extension of the chapter Special Contexts in Part Two, and in this half I describe of some the surprising behaviour with error and transaction handling that you can encounter when you call CLR code from your stored procedures.

The second half of the appendix is an extension to Part Three. Here I take a look at CLR-related issues of two facilities that I introduce in Part Three, SqlEventLog and the CMD Catch Handler. This includes a description of the implementation of the CMD Catch Handler, but I also show some more unexpected behaviour in the interplay between T‑SQL and the CLR.

If you have arrived at this page through a link or a web search, I recommend that you read the prerequisites first. More precisely, for the first half, this is Part One and the first six chapters of Part Two. For the second half, it certainly helps if you have also read Part Three.

Index of All Error-Handling Articles

Here follows a list of all articles in this series:

All the articles above are for SQL 2005 and later. For those who still are on SQL 2000, there are two older articles:

General Scenarios

To work with the examples in this chapter, I recommend that you install error_handler_sp from Part One.

Test Setup

For many of the examples in this appendix, I will use this fairly contrived CLR stored procedure:

using System;
using System.Data;
using System.Data.SqlClient;
using System.Data.SqlTypes;
using Microsoft.SqlServer.Server;

public class errortest {

[Microsoft.SqlServer.Server.SqlProcedure]
public static void clrerrortest(SqlString   sqlcmd,
                                SqlBoolean  usepipe,
                                SqlBoolean  dotry,
                                SqlBoolean  rethrow,
                                SqlBoolean  dorollback) {

   using (SqlConnection cn = new SqlConnection("context connection=true")) {
      SqlCommand cmd = new SqlCommand();
      cn.Open();
      cmd.Connection = cn;
      cmd.CommandText = sqlcmd.ToString();
      if (dotry) {
         try {
            if (usepipe) {
               SqlContext.Pipe.ExecuteAndSend(cmd);
            }
            else {
               cmd.ExecuteNonQuery();
            }
         }
         catch {
            SqlContext.Pipe.Send("Entering the CLR catch handler");
            if (dorollback) {
               cmd.CommandText = "IF @@trancount > 0 ROLLBACK TRANSACTION";
               cmd.ExecuteNonQuery();
            }
            if (rethrow) {
               throw;
            }
         }
      }
      else {
         if (usepipe) {
            SqlContext.Pipe.ExecuteAndSend(cmd);
         }
         else {
            cmd.ExecuteNonQuery();
         }
      }
   }
}
};

If you want to play with the examples on your own, save this code as C:\temp\clrerrortest.cs, and compile it this way:

csc /target:library clrerrortest.cs

If you don't have Visual Studio installed, you still have a C# compiler in C:\Windows\Microsoft.NET\Framework\v2.0.50727 which you can add to your path:

PATH=%PATH%;C:\Windows\Microsoft.NET\Framework\v2.0.50727

Assuming that you have a local SQL Server instance, create the assembly and stored procedure as:

CREATE ASSEMBLY clrerrortest FROM 'C:\temp\clrerrortest.dll'
go
CREATE PROCEDURE clrerrortest 
                 @sqlcmd     nvarchar(MAX),
                 @usepipe    bit = 0, 
                 @dotry      bit = 1,
                 @rethrow    bit = 1,
                 @dorollback bit = 0
AS EXTERNAL NAME clrerrortest.errortest.clrerrortest

If your SQL Server instance is on a different machine, you will need to put the DLL on a share where SQL Server can access it and change the path in the CREATE ASSEMBLY statement appropriately.

Note: You can also create the assembly and the stored procedure through Visual Studio. However, I am not able to give any instructions for Visual Studio, because I don't know how to do it myself.

The procedure accepts an SQL batch in the parameter @sqlcmd and executes it. There are four optional parameters:

In the following, we will call this procedure with batches that cause various types of errors and we will use different values for the flag parameters, with or without a transaction in progress. There are quite a few possible combinations, and I will not explore all of them.

How a Regular CLR Error Looks Like

When a CLR module produces an error, you get the full error stack that you get with a regular .NET program. Here is one example:

EXEC clrerrortest 'Bad-syntax'

This produces:

It's verbose and kind of ugly, but it is the way it is. In the case your CLR code consists of several methods calling each other it may even be helpful. But in an example like this one, where a CLR procedure relays a T‑SQL error, you certainly get a sense of seeing a bit too many trees, leaving you wondering where the forest is.

The default with clrerrortest is to run the command in a try block, catch the exception and rethrow it. You can pass @dotry = 0, to test what happens if there is no try block:

EXEC clrerrortest 'Bad-syntax', @dotry = 0

The output is very similar:

All that is different from the above is that the debug message produced by the catch block in clrerrortest is not there. The reason for this is that there is a built-in catch handler in the CLR integration which makes sure exceptions in the CLR code are propagated to the caller. Nevertheless, I think that you should always have an explicit catch handler in your CLR procedure.

Using try-catch from within the CLR

Since T‑SQL has TRY-CATCH, and C# has try-catch, it is natural to think that they behave the same. And, well, they do – as long as you don't mix them. As you learnt already in Part One, when you nest T‑SQL procedures and an error occurs in an inner procedure without a CATCH block, but there is one in an outer procedure, execution is immediately transferred to this CATCH block. As a repetition, consider this example:

SET NOCOUNT OFF
SET XACT_ABORT OFF
CREATE TABLE Packard(Goose int NOT NULL)
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'SELECT 3/0 INSERT Packard(Goose) VALUES(8)'
BEGIN TRY
   EXEC(@sql)
END TRY
BEGIN CATCH
   EXEC error_handler_sp
END CATCH
SELECT Goose FROM Packard
go
DROP TABLE Packard 

This produces the output:

Not surprisingly, there are no rows in the table, because when the error is raised, the execution is immediately transferred to the CATCH handler, and the INSERT statement is never executed.

But when the error batch is invoked from the CLR, the outcome is different. Look at this:

SET XACT_ABORT OFF
CREATE TABLE Packard(Goose int NOT NULL)
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'SELECT 3/0 INSERT Packard(Goose) VALUES(8)'
EXEC clrerrortest @sql
SELECT Goose FROM Packard
go
DROP TABLE Packard

The output is (with the .NET stack dump replaced by ellipsis):

There is now a row in the table. That is, the INSERT statement was executed, despite that the preceding statement produced an error. The reason for this is that the catch block in the C# procedure does not fire until the T‑SQL block has completed executing. That is, the same thing that would happen if the clrerrortest procedure had been part of a client program.

This behaviour does not change if you wrap the call to clrerrortest in TRY-CATCH; the T‑SQL CATCH does not fire until the CLR reports the error. Nor does it change if you use @dorollback = 1, because there is no transaction to roll back. Neither is there any change if you set @dotry = 0. With @dotry = 1 and @rethrow = 0, the error message goes away, but the row is still inserted.

The key here is that division by zero is a statement-terminating error when XACT_ABORT is OFF. And indeed, if you change the batch to have SET XACT_ABORT ON, the row is not inserted. Another way to prevent the INSERT from happening is to use TRY-CATCH in the T‑SQL batch.

The behaviour is necessarily not evil – sometimes this may be what you want – but it is something you need to be aware of. If you want the execution of your SQL batch to terminate as soon as there is an error, you need to use SET XACT_ABORT ON or trap it with TRY-CATCH within the batch itself. If you rely on XACT_ABORT ON only, you need to take special precautions for the errors that are unaffected by SET XACT_ABORT ON. Particularly, RAISERROR alone will never be enough, but you must make sure that you exit the batch explicitly.

If the behaviour would happen to fit your needs, I need to add the caveat that I am not sure how much you can rely on it. In clrerrortest, I use ExecuteNonQuery. You may see a different behaviour if you use ExecuteReader or DataAdapter.Fill.

The Different Transaction Universes

When you exit a T‑SQL procedure with a different value in @@trancount, this raises error 266. The condition is an error with the CLR as well, but whereas error 266 is mainly noise on the wire, the errors you get with the CLR are far viler. Here is one example:

BEGIN TRANSACTION
EXEC clrerrortest 'bad-syntax', @dorollback = 1
PRINT 'This does not print'
go
PRINT '@@trancount is ' + ltrim(str(@@trancount)) + '.'

Output:

That is, the attempt to roll back from within the C# procedure, resulted in a new error, which masks the original error. The error message has a postlude that comes after the stack dump: User transaction, if any, will be rolled back. When you see this suffix in a .NET error, you know that this was a batch- and transaction-aborting error.

The fact that the batch is aborted is not a big deal, since this can always happen, but losing the original error message is bad, since this makes troubleshooting so much harder. You know that something went wrong, but you don't know what. In this particular example, there is a simple workaround: just wrap the call for the rollback in a local try block with an empty catch block:

catch {
   SqlContext.Pipe.Send("Entering the CLR catch handler");
   if (dorollback) {
      cmd.CommandText = "IF @@trancount > 0 ROLLBACK TRANSACTION";
      try {
         cmd.ExecuteNonQuery();
      }
      catch {
      }
   }
   if (rethrow) {
      throw;
   }
}

However, this will not help if you call some T‑SQL code which rolls back the transaction, for instance in a standard CATCH handler. Here is an example:

SET XACT_ABORT OFF
BEGIN TRANSACTION
DECLARE @sql nvarchar(MAX)
SELECT @sql = 
   'BEGIN TRY 
       SELECT 3/0 
    END TRY 
    BEGIN CATCH 
       IF @@trancount > 0 ROLLBACK TRANSACTION 
    END CATCH'
EXEC clrerrortest @sql

This produces the same error as above. It does not help if you use error_handler_sp in the fashion I suggest in the main parts of the article:

    BEGIN CATCH 
       IF @@trancount > 0 ROLLBACK TRANSACTION 
       EXEC error_handler_sp
    END CATCH'

Since the attempt to roll back the transaction aborts the batch submitted from the CLR, error_handler_sp is never invoked. It works better if you reverse the order:

SET XACT_ABORT OFF
BEGIN TRANSACTION
DECLARE @sql nvarchar(MAX)
SELECT @sql = 
   'BEGIN TRY 
       SELECT 3/0 
    END TRY 
    BEGIN CATCH 
       EXEC error_handler_sp
       IF @@trancount > 0 ROLLBACK TRANSACTION 
    END CATCH'
EXEC clrerrortest @sql

Now you get both error messages:

But this is really only helpful if the T‑SQL code is something you have designed to be called this way. In a real-world situation it is more likely that you would call an existing stored procedure that uses the standard pattern – and which should stick to that pattern. Swapping the order of the reraise and the rollback is not good in the case the caller is another T‑SQL stored procedure with its own TRY-CATCH, because the ROLLBACK statement will not be executed. Yes, the caller may roll back – but we should not trust the caller to do that.

What I have said here applies only if there is an explicit rollback. If the error is batch- and transaction-aborting, but there is no explicit ROLLBACK, the original error message survives:

BEGIN TRANSACTION
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'SELECT convert(int, USER)' 
EXEC clrerrortest @sql

This produces the output:

Here are some more examples of how this strikes, although these examples are maybe more amusing than frightening, since they are due to fairly trivial coding errors.

CREATE TABLE DongWork (Yuda int NOT NULL)
-- BEGIN TRANSACTION
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'BEGIN TRANSACTION INSERT DongWork(Yuda) VALUES (76)' 
EXEC clrerrortest @sql
SELECT Yuda FROM DongWork
go
PRINT '@@trancount is ' + ltrim(str(@@trancount)) + '.'
DROP TABLE DongWork

The output is:

That is, the table is empty, @@trancount is 0, but there is no error. The transaction was silently rolled back. If you uncomment BEGIN TRANSACTION in the outer batch, the scene changes:

This time we got an error message and the batch was aborted. You may note that there is no CLR stack dump here; this is because the error was raised in the T‑SQL universe.

It is perfectly legal to nest T‑SQL and CLR transactions, as long as your BEGIN and COMMIT match up. This executes without any nasty surprises:

CREATE TABLE DongWork (Yuda int NOT NULL)
BEGIN TRANSACTION
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'BEGIN TRANSACTION 
               INSERT DongWork(Yuda) VALUES (76) 
               COMMIT TRANSACTION' 
EXEC clrerrortest @sql
COMMIT TRANSACTION
SELECT Yuda FROM DongWork

The output:

CLR vs. ;THROW

If you use ;THROW in the SQL code you call from the CLR, the behaviour is not like anything we have seen this far:

SET XACT_ABORT OFF
BEGIN TRANSACTION
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'BEGIN TRANSACTION 
              ;THROW 50000, ''Throw a message'', 1'
EXEC clrerrortest @sql
PRINT 'This does not print'
go
PRINT '@@trancount is ' + ltrim(str(@@trancount)) + '.'
IF @@trancount > 0 ROLLBACK TRANSACTION

What do you expect to see here? The message Throw a message embedded in a .NET stack dump? Or a message informing us about the unbalanced BEGIN TRANSACTION? Well, you get neither:

We got the message from ;THROW, but there is no .NET stack dump. The transaction survived the ordeal and for some extra spice, there is a leading newline in the error message. We have learnt that ;THROW aborts the batch without rolling back the transaction, but certainly we expected the catch handler in the C# code to be fired? It wasn't, and it does not stop there. If you wrap the call to clrerrortest in TRY-CATCH:

BEGIN TRY
   EXEC clrerrortest @sql
END TRY
BEGIN CATCH
   EXEC error_handler_sp
END CATCH

You will find that the output is the same. That is, this is an error situation which is entirely uncatchable! Since this error behaviour is new to SQL 2012, my assumption was that this is a bug, and I reported it as such. Microsoft have somehow admitted that it is a bug – because they closed it as Won't Fix rather than By Design. (There is however another bug report on this theme that is still open when I review it in July 2018.) The behaviour is not tied to ;THROW as such; you get the same behaviour if you have a violation of EXECUTE WITH RESULT SETS, or any other situation where Microsoft decides to use this error behaviour after having rolled their what-error-handling-do-we-use-this-time dice.

This quirky behaviour only applies if XACT_ABORT is OFF. If you use SET XACT_ABORT ON (which you should), ;THROW aborts both the batch and the transaction. And if there is a TRY-CATCH around the call to clrerrortest, the error is caught in the CATCH handler.

In the example, there are two extraneous BEGIN TRANSACTION, which I included to show that the normal rollback when you exit the CLR with a different @@trancount was bypassed. If you take out the two BEGIN TRANSACTION statements, you will find that the error is still uncatchable.

Using the Pipe

When you are in a CLR module that operates on the context connection, rather than using ExecuteNonQuery or any of the regular ADO .NET methods, you can use SqlContext.Pipe.ExecuteAndSend. This method executes the command and sends the result – data as well as any messages, errors or informational – directly to the client. It can be disputed how interesting it would be to call such a procedure from T‑SQL, but if nothing else there is INSERT-EXEC.

Let's first look at a simple error:

SET XACT_ABORT OFF
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'Bad-syntax' 
EXEC clrerrortest @sql, @usepipe = 1

This produces:

In addition to the .NET stack trace, we also see an error message in the regular SQL format; this part was sent directly to the client by the ExecuteAndSend method. It's a little redundant with two error messages, but we can avoid the .NET stack trace by having empty catch block in the C# code. With clrerrortest, we can achieve this with setting the parameter @rethrow to 0.

EXEC clrerrortest @sql, @usepipe = 1, @rethrow = 0

The output is now reduced to:

However, there is a catch. Or rather there isn't any where you might expect one to be. To wit, watch what happens when we use @rethrow = 0 within TRY-CATCH:

SET XACT_ABORT OFF
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'Bad-syntax' 
BEGIN TRY
   EXEC clrerrortest @sql, @usepipe = 1, @rethrow = 0
   PRINT 'CATCH handler did not fire'
END TRY
BEGIN CATCH
   PRINT 'Error message:' + error_message()
END CATCH
PRINT 'After the CATCH block'

The resulting output is:

That is, the CATCH block in the T‑SQL code does not fire. I have already told you why: ExecuteAndSend sends the output directly to the client, and whence any CATCH block in the T‑SQL is bypassed. You need to throw an error from the .NET code for that purpose. While somewhat surprising, I don't think this behaviour is particularly evil. After all, having an empty catch block is a conscious action. Note, that if you obliviously leave out try-catch entirely from your CLR procedure, the built-in catch handler will rethrow the error, which you can verify by testing with @dotry = 0.

However, there is more to it. We try a different bad SQL statement:

SET XACT_ABORT OFF
DECLARE @sql nvarchar(MAX)
SELECT @sql = 'EXEC no_such_sp' 
BEGIN TRY
   EXEC clrerrortest @sql, @usepipe = 1, @rethrow = 0
   PRINT 'CATCH handler did not fire'
END TRY
BEGIN CATCH
   PRINT 'Error message:' + error_message()
END CATCH
PRINT 'After the CATCH block'

Now you get this output in Management Studio:

This time we lost original the error message, and got a different one. You may recall from Part Two that this message indicates an internal error in SQL Server or in the client API. And in this case it is the latter. Had there been an internal error in SQL Server, there would have been a stack dump in the SQL Server error log, and there isn't. This is not really related to @rethrow = 0; if you set @rethrow = 1, the CATCH handler fires, but the severe error message appears nevertheless

Interesting enough, when I try the example with clients using OLE DB, ODBC or DB-Library there is no error message at all, but the output is merely:

Which still is incorrect, as the error message is missing.

Exactly what is going on, I don't know, but I suspect that SQL Server generates incorrect TDS, which the other APIs simply ignore. This behaviour exists in SQL 2005 and up. I searched for bug reports, and lo and behold I found that I had reported it myself way back in May 2005 when SQL 2005 was still in beta. Furthermore, the bug was closed as fixed, and they say that the fix would ship with the RTM version of SQL 2005. For whatever reason, that never happened, but the item is still active.

Why do different errors give different behaviour? I have not been able to nail down this exactly. It does not seem to be related to whether the batch has started running or not. For instance, with:

SELECT @sql = 'PRINT SYSTEM_USER; SELECT * FROM nosuch'

I get:

And even more confusing is this:

SELECT @sql = 'SELECT convert(int, newid())'

Conversion from uniqueidentifier to int is not permitted, and this is detected at compile time just like Bad-syntax. Nevertheless, the output is merely:

No T‑SQL error message and no A severe error...

Certainly very confusing. What is important for the second half of this appendix is that errors raised by RAISERROR do not provoke A severe error....

Conclusion

So far in this appendix, you have seen examples of interleaving T‑SQL code and CLR, and you have seen that things do not always work smoothly. Sometimes due to conscious design, like the different transaction universes. Sometimes it seems to be because Microsoft have not tested or analysed all scenarios very closely.

Please bear in mind that this appendix does not claim to uncover all surprises. In order not get buried too deep, I have purposely given a blind eye to ExecuteReader, DataAdapter.Fill etc. That is, I did not even test them. Thus, there are all reasons to be restrictive with mixing T‑SQL and CLR code, and when you do it, keep it simple. And test carefully.

Specific Scenarios

In this chapter, we will discuss some CLR-related topics with SqlEventLog and the CMD Catch Handler that I introduced in Part Three. If you have not read this part yet, you may have some difficulties of following everything I say. Still you will be able to learn about some more surprises you can encounter in the interaction between the T‑SQL and the CLR worlds. If you want to run the examples, you need to have SqlEventLog and the CMD Catch Handler installed in your database. Please see Part Three for how to install them.

CLR and SqlEventLog

So far in this appendix we have used error_handler_sp. If you instead use catchhandler_sp from SqlEventLog, you can expect largely the same behaviour, but there is one quirk we will look at here. But before we come to that I like to discuss an implementation detail of catchhandler_sp – why it always rolls back any open transaction the first thing it does.

Why the Rollback

The underlying issue can be demonstrated with clrerrortest:

SET XACT_ABORT ON
BEGIN TRY
   BEGIN TRANSACTION
   SELECT 3/0
END TRY
BEGIN CATCH
   EXEC clrerrortest 'Bad-syntax'
END CATCH
go
SELECT @@trancount AS trancount
IF @@trancount > 0 ROLLBACK TRANSACTION

The output of this silly script is unexpected:

Operations that write to the log file? We are calling a CLR stored procedure which submits some bad T‑SQL. Yes, the transaction is doomed (because XACT_ABORT is on), but we are not even close to the log file? We can try all sorts of hypotheses, but to make the story short: it is the mere fact that we are calling the CLR procedure that causing the message. No, a call to a CLR procedure does not write to the log file, but for some reason Microsoft added a check to ban calls to CLR procedures in doomed transactions. The ban applies to stored procedures only; you can still call CLR functions from doomed transactions.

Why the behaviour is not there, I don't know. But I have not filed a bug report for it for two reasons: 1) It seems clear that it is by design. 2) To be honest, I don't really see the use case for calling CLR stored procedures from doomed transactions.

The last point may seem somewhat strange, give that an implication of this ban is that you cannot use sqleventlog_sp in a CATCH handler:

SET XACT_ABORT ON
BEGIN TRY
   BEGIN TRANSACTION
   SELECT 3/0
END TRY
BEGIN CATCH
   DECLARE @msg nvarchar(2048) = error_message()
   EXEC slog.sqleventlog_sp @@procid, @msg
END CATCH

You get the output:

You may note that the original message is not lost, since sqleventlog_sp attempts to raise the input message if there is an unexpected error during execution. But the message is not logged to the table as planned.

However, I am not sure I see any reason to call sqleventlog_sp directly in a CATCH handler, but rather you would call catchhandler_sp. Yes, this procedure calls sqleventlog_sp, so you may think there is a problem. But recall that you are supposed to have this line first in your CATCH handler, before you call catchhandler_sp:

IF @@trancount > 0 ROLLBACK TRANSACTION

And, as I mentioned above, if you omit the rollback, catchhandler_sp will roll back the transaction the first thing it does, unconditionally, which is why this issue never arises with the call to sqleventlog_sp.

The original reason for the rollback in catchhandler_sp is not this mysterious ban, though. When I first wrote the precursor to catchhandler_sp quite a few years ago, I did run into this restriction of the simple reason that in those days we used an extended stored procedure for the loopback, for which there is no ban in doomed transactions. (The full concept of SqlEventLog is way older than SQL 2005 and TRY-CATCH, and the CLR loopback came later.) I simply added the rollback because it seemed to be the right thing to do. Originally, I had a parameter to suppress the rollback, but checking our code, I find that we have never used it. Nor could I really think of a situation when you would. And when I found out about this ban, it was a simple decision to rip out the parameter entirely.

A Security Restriction

The second issue with SqlEventLog can be demonstrated with this batch:

EXEC clrerrortest 'BEGIN TRANSACTION 
                   EXEC slog.sqleventlog_sp @@procid, ''Streck ihn aus''
                   COMMIT TRANSACTION'

The output depends on how you built SqlEventLog. If you built it with .NET 2.0, you get the expected output:

And if you look in the sqleventlog table, the message is there. But if you built SqlEventLog with .NET 4.x or later, the message is not logged and you get this burst of output:

The exception Cannot perform CAS Asserts in Security Transparent methods is thrown by the SQLCLR, because the loopback assembly has a higher permission set (EXTERNAL ACCESS) than the SAFE assembly for clrerrortest. The check as such is not new to .NET 4, but I originally ran into this issue when I used .NET 2.0. My MVP colleague Adam Machanic was nice to provide me with some code that I could add to loopback_sp to prevent this exception from being thrown:

SqlClientPermission scp = new SqlClientPermission (
      System.Security.Permissions.PermissionState.Unrestricted);
scp.Assert();

For me, this piece of code is completely mumbo-jumbo, but Adam has written about it in this article.

Later, I found that this snippet does not prevent the exception with .NET 4. Adam was kind to give it a second look, and he suggested two attributes that I added to the loopback assembly. And I am sure that I had it working at some point, but now it doesn't. Maybe some fix that came with Windows Update broke it. Maybe it was something in SQL 2012 SP2. Whatever, I decided that it was not worth the trouble to spend more time on finding a solution. After all, as long as you build SqlEventLog with .NET 2.0 there is no issue.

Implementation of the CMD Catch Handler

In this section, we will take a look at the implementation of CMD Catch Handler. In case you have forgotten it, here is a quick recap: The CMD Catch Handler is an extension to SqlEventLog and the public API is the stored procedure slog.cmd_catchhandler_sp. It takes one mandatory parameter which is a T‑SQL batch. The CMD Catch Handler runs this batch, and if there are errors, the errors are sent to the client as well as logged to slog.sqleventlog. The CMD Catch Handler is primarily intended for commands that may produce multiple errors message like BACKUP/RESTORE and DDL.

The full code for cmd_catchhandler_sp is simple:

CREATE PROCEDURE slog.cmd_catchhandler_sp
                 @cmdtext   nvarchar(MAX),
                 @procid    int      = NULL,
                 @trycatch  bit      = 0,
                 @quotechar nchar(1) = NULL AS

DECLARE @dbname   sysname,
        @username sysname,
        @appname  sysname,
        @hostname sysname,
        @ret      int


SELECT @dbname = db_name(), @username = SYSTEM_USER, @appname = app_name(),
       @hostname = host_name()

EXEC @ret = slog.cmd_catchhandler_clr_sp @cmdtext, @procid, @trycatch,
                                  @quotechar, @@servername, @dbname,
                                  @username, @appname, @hostname
RETURN isnull(@ret, 1)

That is, it is a T‑SQL procedure that picks up some auditing information before calling a CLR procedure where the real action is. This is the outline: The command is executed on the context connection using the pipe. Any errors are caught and logged to the table slog.sqleventlog. The error messages are also sent directly to the client. If the parameter @trycatch (which indicates that the CMD Catch Handler has been invoked from a TRY block) is 1, the errors are also reraised so that they can be caught by CATCH in T‑SQL.

The full code for cmd_catchhandler_clr_sp is available in cmd_catchhandler.cs (opens in a separate window), included in the SqlEventLog download. I'm not showing the full code here, only the pertinent parts.

The first thing to appear in this file is a private class, MessageGatherer, which has one private member.

System.Collections.Generic.List<SqlError> _messages;

That is, a collection of SQL messages (not necessarily only errors). The class has a get method and a constructor that are plain vanilla:

public System.Collections.Generic.List<SqlError> messages {
   get { return this._messages;}
}

public MessageGatherer () {
   _messages = new System.Collections.Generic.List<SqlError>();
}

There are also two methods to add data to the collection:

public void message_handler (Object sender,
                             SqlInfoMessageEventArgs msg) {
    foreach (SqlError err in msg.Errors) {
        _messages.Add(err);
    }
}

public void add_messages (SqlErrorCollection errs) {
    foreach (SqlError err in errs) {
        _messages.Add(err);
    }
}

The signature of the first method may seem mysterious, but the reason will prevail in just a second.

Next follows the procedure declaration which I don't take up space with here. The first thing that happens in the procedure itself is the implementation of the @quotechar parameter:

if (! quotechar.IsNull) {
   cmdtext = cmdtext.Replace(quotechar.Value, "'");
}

This parameter permits you to use an alternate quote character in the batch you submit, for instance:

EXEC slog.cmd_catchhandler_sp 
     'BACKUP DATABASE mydb TO DISK = "C:\temp\mybackup.bak"', @quotechar = '"'

Next, I instantiate the MessageGatherer class and set up a connection object for the context connection:

MessageGatherer message_gatherer = new MessageGatherer();

using (SqlConnection ctx_cn = new SqlConnection("context connection=true"))
{
   ctx_cn.Open();
   ctx_cn.InfoMessage += message_gatherer.message_handler;
   ctx_cn.FireInfoMessageEventOnUserErrors = true;

I want to capture all messages produced by the @cmdtext parameter. In order to do this, I set up a handler for the InfoMessage event and to this end, I use the message_handler method in the MessageGatherer class. This is why this method has this particular signature; it must match the InfoMessage event. Furthermore, I want the same behaviour for errors and informational messages and I achieve this by setting the connection property FireInfoMessageEventOnUserErrors. This causes all errors with severity level ≤ 16 to raise an InfoMessage event rather than throwing an exception.

Next I run the T‑SQL batch. I do this in a way that we have not looked at in this appendix before:

SqlCommand cmd = new SqlCommand(cmdtext, ctx_cn);
cmd.CommandType = CommandType.Text;
try {
   using (SqlDataReader reader = cmd.ExecuteReader()) {
      SqlContext.Pipe.Send(reader);
   }
}
catch (SqlException ex) {
   message_gatherer.add_messages(ex.Errors);
}

Rather than using ExecuteAndSend, I use an overload of the SqlPipe.Send method that accepts an SqlDataReader object as parameter. Send(SqlDataReader) works like ExecuteAndSend so far that all result sets produced are sent to the client, but messages – errors and informational – are not. This way, I could (mainly) avoid the message A severe error occurred on the current command. The results, if any, should be discarded. This arrangement is not perfect, and we will look at some true weirdness later on. There is a catch handler, since even if I have set the property with the very long name, I still need to consider errors with severity ≥ 17. If such errors appear, I add them to the MessageGatherer object, so that I have all messages in one place.

Once the command batch has been executed, I make some preparations for the analysis of the outcome of the batch:

ctx_cn.InfoMessage -= message_gatherer.message_handler;
ctx_cn.FireInfoMessageEventOnUserErrors = false;

Int32  retvalue = 0; 
String fullerrmsg = String.Empty;

If there are any messages in the MessageGatherer object, I will use the context connection again, but this time I don't want to any InfoMessage events raised, but I want the default behaviour. I also initiate some variables for the rest of the work. retvalue is the return value from the CMD Catch Handler. fullerrmsg will hold a concatenation of all error messages that occurred; this variable is used when the parameter @trycatch is 1.

Next follows a loop over the gathered messages and which runs almost to the end of the procedure:

foreach (SqlError msgobj in message_gatherer.messages) {

The loop performs three tasks for every message. Or more precisely one task is performed for all messages, errors and informational messages alike, and the other two tasks are performed only for errors:

• All messages: send them to the client.
• Errors only: set the return value and aggregate to fullerrmsg.
• Errors only: log the error to SqlEventLog.

The most intriguing part is the first. We have the messages in the MessageGatherer object, but how do we send them to the client? SqlPipe.Send(String) would be good for the informational messages, but not the errors as they would not be presented as such. Rather, the answer is RAISERROR through ExecuteAndSend. There are some preparations before we come that far:

System.Text.StringBuilder sb = new System.Text.StringBuilder();
if (msgobj.Class > 0) {
   sb.Append("{");
   sb.Append(msgobj.Number);
   sb.Append("} ");
}
sb.Append(msgobj.Message);

This prepares the message itself. Since the error is reraised through RAISERROR, the error number will be 50000. To preserve the original error number, I prepend the error number in braces to the error message just like I do in catchhandler_sp in SqlEventLog.

Note: You may recall from Part Three that in catchhandler_sp I also add the procedure name and line number to the error message. I don't do this here, because I found when testing that the Procedure and Line properties of the SqlError object are always empty/zero in this context. I have no idea why, and I have not filed a bug for it on Uservoice. Since the CMD Catch Handler is mainly intended for single-command batches, this is not much of an issue anyway.

Of the remaining parameters to RAISERROR, we need to make sure that the severity is ≤ 18 to avoid the need for WITH LOG. The message as such is only a parameter holder %s, and the message is passed as a parameter to avoid problems with per-cent characters. (See the section on RAISERROR in Part Two for an elaboration on these two points.) This results in this code to run RAISERROR:

SqlCommand raisecmd = new SqlCommand(
          "RAISERROR('%s', @severity, @state, @msg)", ctx_cn);
raisecmd.Parameters.Add("@msg", SqlDbType.NVarChar, 2048);
raisecmd.Parameters["@msg"].Value = sb.ToString();
raisecmd.Parameters.Add("@severity", SqlDbType.TinyInt);
raisecmd.Parameters["@severity"].Value =
        (msgobj.Class <= 18 ? msgobj.Class : (Byte) 18);
raisecmd.Parameters.Add("@state", SqlDbType.TinyInt);
raisecmd.Parameters["@state"].Value = msgobj.State;

try {
   SqlContext.Pipe.ExecuteAndSend(raisecmd);
}
catch  {}

Note the empty catch handler to suppress the SQLCLR integration from rethrowing the error.

Next task is to set the return value and extend fullerrmsg, and this is less exciting:

if (msgobj.Class >= 11) {
   if (retvalue == 0) {
      fullerrmsg = msgobj.Message;
      retvalue = msgobj.Number;
   }
   else {
      fullerrmsg = string.Concat(fullerrmsg, "\r\n", msgobj.ToString());
   }

If retvalue is 0, this is the first error message.

The final task to perform is to log the message to SqlEventLog. If there is an active transaction, this must be done over the loopback connection so that the log entry survives a rollback. If you have read about SqlEventLog, you know that the appropriate tool for this task is the stored procedure slog.sqleventlog_sp, which calls the internal procedure slog.log_insert_sp, either directly or through loopback_sp if there is an active transaction.

However, this would not work if the error has resulted in a doomed transaction (as we learnt in the previous section, it is not permitted to call CLR procedure in a doomed transaction). There is also another complication: In the CMD Catch Handler, I want to log the cmdtext column to the sqleventlog table, but this column is not handled by the procedures sqleventlog_sp, loopback_sp and log_insert_sp, as this column is added first when you install the CMD Catch Handler. Instead there is a separate procedure, slog.add_cmdtext_sp to write the value of the @cmdtext parameter to the cmdtext column. And this procedure, too, has to be called over a loopback connection if there is a transaction in progress.

For this reason, I decided to call slog.log_insert_sp directly and I also decided to always use a loopback connection to keep things simple. The code to call log_insert_sp and add_cmdtext_sp is routine code and nothing I take up space with here. The only thing to observe is one detail where I set up the connection:

SqlConnectionStringBuilder loopback_string = new SqlConnectionStringBuilder();
loopback_string.DataSource = server;
loopback_string.InitialCatalog = dbname;
loopback_string.IntegratedSecurity = true;
loopback_string.Enlist = false;

using (SqlConnection loop_cn =
          new SqlConnection(loopback_string.ConnectionString)) {

Just like in loopback_sp, the Enlist property must be set to false to avoid that the loopback connection becomes part of the enclosing transaction.

Once we are out of the loop over the MessageGatherer object, there is code to handle the @trycatch parameter. That is, if this parameter is 1, we were presumably called from a TRY-CATCH block in T‑SQL and if any errors occurred when running the command batch, we should throw an exception to fire the CATCH handler in the calling T‑SQL code. This is where fullerrmsg comes into play:

if (trycatch && retvalue != 0) {
   throw new Exception (fullerrmsg);
}

return retvalue;

Note that if @trycatch is 1 and there was one or more error messages, the return statement will not be executed and the CLR procedure will return NULL. You may recall that the T‑SQL wrapper had this statement:

RETURN isnull(@ret, 1)

So in case you by mistake pass @trycatch = 1 outside a TRY block, you will still get a non-zero return value back.

Fun(?) with the CMD Catch Handler

When I presented the CMD Catch Handler in Part Three, I remarked the it's fairly clunky to use. I also said if you use it, you are better off using it with single-command batches. In this section, we will look at some weird things that can happen if you run longer segments of code through the CMD Catch Handler.

First just a simple observation about XACT_ABORT ON. This works without surprises:

SET XACT_ABORT OFF
go
CREATE TABLE Watermelon (EasternHay int NOT NULL)
EXEC slog.cmd_catchhandler_sp 
     'SELECT 3/0; INSERT Watermelon(EasternHay) VALUES (9)'
SELECT EasternHay FROM Watermelon
go
DROP TABLE Watermelon

The output is:

Because division by zero is a statement-terminating error, execution continues with the INSERT statement. Change to SET XACT_ABORT ON and the output becomes:

The table is empty – but the SELECT statement after the call to cmd_catchhandler_sp still executes despite that XACT_ABORT was ON, and it was only the batch passed to the CMD Catch Handler that was aborted. When you execute a batch this way – through SqlPipe.Send(SqlDataReader) – a batch-aborting error only aborts the batch submitted through the SqlDataReader. The outer batch is not affected. Whence the recommendation to always look at the return code from cmd_catchhandler_sp.

And now for something truly crazy. Here is the setup:

CREATE TABLE Chungas(Revenge int         NOT NULL CONSTRAINT pk PRIMARY KEY,
                     Batch   varchar(10) NOT NULL)
go
CREATE PROCEDURE FirstBatch AS 
    RAISERROR('First message', 9, 1)
    INSERT Chungas(Revenge, Batch) VALUES (89, 'First')
    RAISERROR('Second message', 11, 1)
    INSERT Chungas(Revenge, Batch) VALUES (189, 'First')
    RAISERROR('Third message', 13, 1)
go
CREATE PROCEDURE SecondBatch AS
    INSERT Chungas(Revenge, Batch) VALUES (89, 'Second')
    INSERT Chungas(Revenge, Batch) VALUES (89, 'Second')
    INSERT Chungas(Revenge, Batch) VALUES (89, 'Second')
    INSERT Chungas(Revenge, Batch) VALUES (289, 'Second')
go

There is a table with a primary key, and two stored procedures. FirstBatch produces three messages with severity levels 9, 11, and 13. And in between, it inserts two rows in the Chungas table. In the second procedure, there are four INSERT statements, whereof the first three use the same key values as the first procedure, and thus will produce PK violations.

Using this table and these procedures, we have this test script, where we first run the two stored procedures through the CMD Catch Handler. Next we run another suite of statements, with the same pattern as in the stored procedures but with different key values.

SET XACT_ABORT OFF
SET NOCOUNT OFF
EXEC slog.cmd_catchhandler_sp 'EXEC FirstBatch'
PRINT '-------------------'

EXEC slog.cmd_catchhandler_sp 'EXEC SecondBatch'
PRINT '-------------------'

EXEC slog.cmd_catchhandler_sp 
    'RAISERROR("First message", 9, 1)
     INSERT Chungas(Revenge, Batch) VALUES (309, "Third")
     RAISERROR("Second message", 11, 1)
     INSERT Chungas(Revenge, Batch) VALUES (389, "Third")
     RAISERROR("Third message", 13, 1)', @quotechar = '"'
PRINT '-------------------'

EXEC slog.cmd_catchhandler_sp 
    'INSERT Chungas(Revenge, Batch) VALUES (389, "Fourth")
     INSERT Chungas(Revenge, Batch) VALUES (389, "Fourth")
     INSERT Chungas(Revenge, Batch) VALUES (389, "Fourth")
     INSERT Chungas(Revenge, Batch) VALUES (489, "Fourth")', @quotechar = '"'

SELECT Revenge, Batch FROM Chungas

This produces a lot of output, but there are no surprises. Keys 89 and 189 are inserted from the first batch, while key 289 is from the second batch. And likewise, keys 309 and 389 are from the third batch and key 489 comes from the fourth:

Note: this output is from SQL 2008 and up. It is slightly different on SQL 2005 which does not give you the value of the duplicate key and where you for some reason only get The statement has been terminated once per batch.

Now truncate the table and wrap the calls to the CMD Catch Handler in TRY-CATCH. Since we don't specify @trycatch = 1, the CMD Catch Handler will not raise the error in a way that fires the CATCH handler.

TRUNCATE TABLE Chungas
BEGIN TRY
   EXEC slog.cmd_catchhandler_sp 'EXEC FirstBatch'
END TRY BEGIN CATCH PRINT 'Nope' END CATCH
PRINT '-------------------'

BEGIN TRY
   EXEC slog.cmd_catchhandler_sp 'EXEC SecondBatch'
END TRY BEGIN CATCH PRINT 'Nope' END CATCH
PRINT '-------------------'

BEGIN TRY
EXEC slog.cmd_catchhandler_sp 
    'RAISERROR("First message", 9, 1)
     INSERT Chungas(Revenge, Batch) VALUES (309, "Third")
     RAISERROR("Second message", 11, 1)
     INSERT Chungas(Revenge, Batch) VALUES (389, "Third")
     RAISERROR("Third message", 13, 1)', @quotechar = '"'
END TRY BEGIN CATCH PRINT 'Nope' END CATCH
PRINT '-------------------'

BEGIN TRY
EXEC slog.cmd_catchhandler_sp 
    'INSERT Chungas(Revenge, Batch) VALUES (389, "Fourth")
     INSERT Chungas(Revenge, Batch) VALUES (389, "Fourth")
     INSERT Chungas(Revenge, Batch) VALUES (389, "Fourth")
     INSERT Chungas(Revenge, Batch) VALUES (489, "Fourth")', @quotechar = '"'
END TRY BEGIN CATCH PRINT 'Nope' END CATCH

SELECT Revenge, Batch FROM Chungas

This changes the output:

The output from the execution of the stored procedures is the same. But for the batches without stored procedures, there are three differences:

1. In the output from the third batch, we don't see the last error Third message.
2. In the output from the fourth batch, there are only two PK errors, not three.
3. In the data from the Chungas table, key 389 is now said to have been inserted from the fourth batch, not the third.

What can we say about this? Had the message Third message just been dropped on the floor, the third batch would still have inserted key 389. Thus, we must conclude that neither the INSERT statement for 389 nor the last RAISERROR statement was executed. That is, the third batch was aborted. By which statement? There is only one suspect: RAISERROR. RAISERROR that we have learnt so far never aborts the batch, no matter the setting of XACT_ABORT. But here, when invoked through SqlPipe(SqlDataReader) it suddenly becomes batch-aborting when executed outside a stored procedure, even with XACT_ABORT is OFF. And only if there is an enclosing TRY-CATCH block. I did not test this vigorously, but we can tell from the fourth batch that this is not a general thing – the PK violations do not abort the batch. (We get one less, simply because one of the INSERT statements succeeds.)

I am completely baffled and without explanation. It is quite likely that this is not a conscious design. In fact, I don't see this behaviour on SQL 2005. But I have not bothered to file a bug on Uservoice, because I find it unlikely that Microsoft would bother.

In any case, this is why I recommend that you use CMD Catch Handler outside TRY-CATCH and with simple statements. Who knows what other surprises that might be hiding there.

Revision History

Below is a revision history for this appendix. For a list of acknowledgements, please see the end of Part Three. If you have questions specific on the contents in this appendix, please feel free to mail me on [email protected]. Remarks on spelling and grammar errors are more than welcome!

2015-05-03

First version.

Back to my home page.