当触发器中执行的方法中发生异常时，日志记录不持久

Question

我整天都被这个问题所困扰，似乎无法在网上找到任何可以指出可能导致它的原因。

我在 Logger 类中有以下日志记录方法，以下代码调用记录器。当没有异常发生时，所有日志语句都可以正常工作，但是当异常发生时，日志语句根本不会运行（但是它们确实从 Web 服务调用中运行）。

Logger 记录方法：

    public static Guid WriteToSLXLog(string ascendId, string masterDataId, string masterDataType, int? status,
        string request, string requestRecieved, Exception ex, bool isError)
    {
        var connection = ConfigurationManager.ConnectionStrings["AscendConnectionString"];

        string connectionString = "context connection=true";

        // define INSERT query with parameters
        var query =
            "INSERT INTO " + AscendTable.SmartLogixLogDataTableName +
            " (LogID, LogDate, AscendId, MasterDataId, MasterDataType, Status, Details, Request, RequestRecieved, StackTrace, IsError) " +
            "VALUES (@LogID, @LogDate, @AscendId, @MasterDataId, @MasterDataType, @Status, @Details, @Request, @RequestRecieved, @StackTrace, @IsError)";

        var logId = Guid.NewGuid();

        using (var cn = new SqlConnection(connectionString))
        {
            if (!cn.State.Equals(ConnectionState.Open))
            {
                cn.Open();
            }
            // create command
            using (var cmd = new SqlCommand(query, cn))
            {
                try
                {
                    // define parameters and their values
                    cmd.Parameters.Add("@LogID", SqlDbType.UniqueIdentifier).Value = logId;
                    cmd.Parameters.Add("@LogDate", SqlDbType.DateTime).Value = DateTime.Now;
                    if (ascendId != null)
                    {
                        cmd.Parameters.Add("@AscendId", SqlDbType.VarChar, 24).Value = ascendId;
                    }
                    else
                    {
                        cmd.Parameters.Add("@AscendId", SqlDbType.VarChar, 24).Value = DBNull.Value;
                    }
                    cmd.Parameters.Add("@MasterDataId", SqlDbType.VarChar, 50).Value = masterDataId;
                    cmd.Parameters.Add("@MasterDataType", SqlDbType.VarChar, 50).Value = masterDataType;

                    if (ex == null)
                    {
                        cmd.Parameters.Add("@Status", SqlDbType.VarChar, 50).Value = status.ToString();
                    }
                    else
                    {
                        cmd.Parameters.Add("@Status", SqlDbType.VarChar, 50).Value = "2";
                    }

                    if (ex != null)
                    {
                        cmd.Parameters.Add("@Details", SqlDbType.VarChar, -1).Value = ex.Message;
                        if (ex.StackTrace != null)
                        {
                            cmd.Parameters.Add("@StackTrace", SqlDbType.VarChar, -1).Value =
                                ex.StackTrace;
                        }
                        else
                        {
                            cmd.Parameters.Add("@StackTrace", SqlDbType.VarChar, -1).Value = DBNull.Value;
                        }
                    }
                    else
                    {
                        cmd.Parameters.Add("@Details", SqlDbType.VarChar, -1).Value = "Success";
                        cmd.Parameters.Add("@StackTrace", SqlDbType.VarChar, -1).Value = DBNull.Value;
                    }

                    if (!string.IsNullOrEmpty(request))
                    {
                        cmd.Parameters.Add("@Request", SqlDbType.VarChar, -1).Value = request;
                    }
                    else
                    {
                        cmd.Parameters.Add("@Request", SqlDbType.VarChar, -1).Value = DBNull.Value;
                    }

                    if (!string.IsNullOrEmpty(requestRecieved))
                    {
                        cmd.Parameters.Add("@RequestRecieved", SqlDbType.VarChar, -1).Value = requestRecieved;
                    }
                    else
                    {
                        cmd.Parameters.Add("@RequestRecieved", SqlDbType.VarChar, -1).Value = DBNull.Value;
                    }

                    if (isError)
                    {
                        cmd.Parameters.Add("@IsError", SqlDbType.Bit).Value = 1;
                    }
                    else
                    {
                        cmd.Parameters.Add("@IsError", SqlDbType.Bit).Value = 0;
                    }

                    // open connection, execute INSERT, close connection
                    cmd.ExecuteNonQuery();
                }
                catch (Exception e)
                {
                    // Do not want to throw an error if something goes wrong logging
                }
            }
        }

        return logId;
    }

发生日志记录问题的我的方法：

public static void CallInsertTruckService(string id, string code, string vinNumber, string licPlateNo)
    {
        Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "1", "", null, false);
        try
        {
            var truckList = new TruckList();
            var truck = new Truck();

            truck.TruckId = code;

            if (!string.IsNullOrEmpty(vinNumber))
            {
                truck.VIN = vinNumber;
            }
            else
            {
                truck.VIN = "";
            }

            if (!string.IsNullOrEmpty(licPlateNo))
            {
                truck.Tag = licPlateNo;
            }
            else
            {
                truck.Tag = "";
            }

            if (!string.IsNullOrEmpty(code))
            {
                truck.BackOfficeTruckId = code;
            }

            truckList.Add(truck);

            Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "2", "", null, false);

            if (truckList.Any())
            {
                // Call SLX web service
                using (var client = new WebClient())
                {
                    var uri = SmartLogixConstants.LocalSmartLogixIntUrl;


                    uri += "SmartLogixApi/PushTruck";

                    client.Headers.Clear();
                    client.Headers.Add("content-type", "application/json");
                    client.Headers.Add("FirestreamSecretToken", SmartLogixConstants.FirestreamSecretToken);

                    var serialisedData = JsonConvert.SerializeObject(truckList, new JsonSerializerSettings
                    {
                        ReferenceLoopHandling = ReferenceLoopHandling.Serialize
                    });

                    // HTTP POST
                    var response = client.UploadString(uri, serialisedData);

                    var result = JsonConvert.DeserializeObject<SmartLogixResponse>(response);

                    Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "3", "", null, false);

                    if (result == null || result.ResponseStatus != 1)
                    {
                        // Something went wrong
                        throw new ApplicationException("Error in SLX");
                    }

                    Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, result.ResponseStatus, serialisedData,
                        null, null, false);
                }
            }
        }
        catch (Exception ex)
        {
            Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "4", "", null, false);
            throw;
        }
        finally
        {
            Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "5", "", null, false);
        }
    }

如您所见，我在整个方法中添加了几个日志语句。如果没有抛出异常，所有这些日志语句除了在 catch 块中的语句都是成功的。如果抛出异常，那么它们都不会成功。对于他们中的大多数人来说，无论是否存在异常，值都是完全相同的，所以我知道传递的值不是问题。我在想一些奇怪的事情正在发生，导致回滚或其他事情，但我没有在这里使用事务或任何东西。最后一件事是这个 DLL 正在通过 SQL CLR 运行，这就是我使用“context connection=true”作为连接字符串的原因。

提前致谢。

编辑：

我尝试将以下内容添加为我的连接字符串，但在尝试打开连接时出现异常，现在显示“另一个会话正在使用事务上下文”。我认为这与我通过触发器调用此 SQL CLR 过程有关。我试过的连接字符串是

 connectionString = "Trusted_Connection=true;Data Source=(local)\\AARONSQLSERVER;Initial Catalog=Demo409;Integrated Security=True;";  

这里也是触发器：

CREATE TRIGGER [dbo].[PushToSLXOnVehicleInsert]
   ON  [dbo].[Vehicle] AFTER INSERT
AS 
BEGIN
-- SET NOCOUNT ON added to prevent extra result sets from
-- interfering with SELECT statements.
SET NOCOUNT ON;
DECLARE @returnValue int
DECLARE @newLastModifiedDate datetime = null
DECLARE @currentId bigint = null
DECLARE @counter int = 0;
DECLARE @maxCounter int
DECLARE @currentCode varchar(24) = null
DECLARE @currentVinNumber varchar(24)
DECLARE @currentLicPlateNo varchar(30)
declare @tmp table
(
  id int not null
  primary key(id)
)

insert @tmp
select VehicleID from INSERTED

SELECT @maxCounter = Count(*) FROM INSERTED GROUP BY VehicleID

BEGIN TRY
WHILE (@counter < @maxCounter)
BEGIN       
    select top 1 @currentId = id from @tmp

    SELECT @currentCode = Code, @currentVinNumber = VINNumber, @currentLicPlateNo = LicPlateNo FROM INSERTED WHERE INSERTED.VehicleID = @currentId

    if (@currentId is not null)
    BEGIN
        EXEC dbo.SLX_CallInsertTruckService
            @id = @currentId,
            @code = @currentCode,
            @vinNumber = @currentVinNumber,
            @licPlateNo = @currentLicPlateNo
    END

    delete from @tmp where id = @currentId

    set @counter = @counter + 1;
END
END TRY
BEGIN CATCH
    DECLARE @ErrorMessage NVARCHAR(4000);
    DECLARE @ErrorSeverity INT;
    DECLARE @ErrorState INT;

    SELECT 
        @ErrorMessage = ERROR_MESSAGE(),
        @ErrorSeverity = ERROR_SEVERITY(),
        @ErrorState = ERROR_STATE();
    IF (@ErrorMessage like '%Error in SLX%')
    BEGIN
        SET @ErrorMessage = 'Error in SLX.  Please contact SLX for more information.'
    END
    RAISERROR (@ErrorMessage, -- Message text.
               @ErrorSeverity, -- Severity.
               @ErrorState -- State.
               );
END CATCH;
END
GO

Answer 1

这里的主要问题是 SQLCLR 存储过程是从触发器中调用的。触发器始终在事务的上下文中运行（将其绑定到启动触发器的 DML 操作）。触发器还会将XACT_ABORT 隐式设置为ON，如果发生任何 错误，则会取消事务。这就是为什么在抛出异常时没有任何日志记录语句持续存在的原因：事务是自动回滚的，它会携带在同一会话中所做的任何更改，包括日志记录语句（因为Context Connection 是同一个会话） ，以及原始的 DML 语句。

您有三个相当简单的选项，尽管它们会给您留下一个整体架构问题，或者一个不那么困难但需要更多工作的选项来解决当前问题以及更大的架构问题.一、三个简单的选项：

1. 您可以在触发器的开头执行SET XACT_ABORT OFF;。这将允许TRY ... CATCH 构造按照您的预期工作。但是，这也将责任转移给您发出ROLLBACK（通常在CATCH 块中），除非您希望原始DML 语句无论如何都成功，即使Web 服务调用和日志记录失败。当然，如果您发出ROLLBACK，那么即使 Web 服务仍然注册所有成功的调用（如果有的话），任何日志记录语句都不会保留。

2. 您可以不理会SET XACT_ABORT，而是使用常规/外部连接到 SQL Server。常规连接将是完全独立的连接和会话，因此它可以独立于事务操作。与SET XACT_ABORT OFF; 选项不同，这将允许触发器“正常”运行（即，任何错误都将回滚触发器中的任何本地更改以及原始 DML 语句），同时仍允许记录 INSERT 语句持续存在（因为它们是在本地事务之外进行的）。

   您已经在调用 Web 服务，因此程序集已经拥有执行此操作所需的权限，而无需进行任何其他更改。您只需要使用正确的connection string（您的语法中有一些错误），可能类似于：

   connectionString = @"Trusted_Connection=True; Server=(local)\AARONSQLSERVER; Database=Demo409; Enlist=False;"; 
   

   "Enlist=False;" 部分（滚动到最右侧）非常重要：没有它，您将继续收到“Transaction context in use by another session”错误。

3. 如果您想坚持使用Context Connection（它会快一点）并允许任何错误在Web 服务之外回滚原始DML 语句和 所有日志记录语句，同时忽略来自 Web 服务的错​​误，或者甚至来自日志记录 INSERT 语句的错误，那么您就不能在 CallInsertTruckService 的 catch 块中重新抛出异常。您可以改为设置一个变量来指示返回码。由于这是一个存储过程，它可以返回SqlInt32 而不是void。然后，您可以通过声明 INT 变量并将其包含在 EXEC 调用中来获取该值，如下所示：

   EXEC @ReturnCode = dbo.SLX_CallInsertTruckService ...;
   

   只需在CallInsertTruckService 的顶部声明一个变量并将其初始化为0。然后将其设置为 catch 块中的其他值。并在方法的末尾添加一个return _ReturnCode;。

话虽如此，无论您选择哪一个，您仍然面临两个相当大的问题：

1. DML 语句及其系统启动的事务受到 Web 服务调用的阻碍。事务将保持打开状态的时间比应有的时间长得多，这至少会增加与Vehicle 表相关的阻塞。虽然我当然提倡通过 SQLCLR 进行 Web 服务调用，但我强烈建议不要在触发器中这样做。

2. 如果插入的每个 VehicleID 都应该传递给 Web 服务，那么如果在一个 Web 服务调用中出现错误，则剩余的 VehicleIDs 将被跳过，即使它们不在't（上面的选项 #3 将继续处理 @tmp 中的行）然后至少以后不会重试刚刚出现错误的行。

因此，解决这两个相当重要的问题以及初始日志记录问题的理想方法是转向断开连接的异步模型。您可以设置一个队列表来保存基于每个INSERT 处理的车辆信息。触发器会做一个简单的事情：

INSERT INTO dbo.PushToSLXQueue (VehicleID, Code, VINNumber, LicPlateNo)
  SELECT VehicleID, Code, VINNumber, LicPlateNo
  FROM   INSERTED;

然后创建一个存储过程，从队列表中读取一个项目，调用 Web 服务，如果成功，然后从队列表中删除该条目。从 SQL Server 代理作业安排此存储过程每隔 10 分钟或类似的时间运行一次。

如果有永远不会处理的记录，那么您可以在队列表中添加一个RetryCount 列，默认为0，当Web 服务出现错误时，增加RetryCount 而不是删除该行。然后您可以更新“获取处理条目”SELECT 查询以包含 WHERE RetryCount < 5 或您要设置的任何限制。

---

这里有几个问题，影响程度不同：

1. 为什么 id 在 T-SQL 代码中是 BIGINT 而在 C# 代码中是字符串？

2. 仅供参考，与使用实际的 CURSOR 相比，WHILE (@counter < @maxCounter) 循环效率低且容易出错。我会摆脱@tmp 表变量和@maxCounter。

   至少将 SELECT @maxCounter = Count(*) FROM INSERTED GROUP BY VehicleID 更改为 SET @maxCounter = @@ROWCOUNT; ;-)。但是最好换成真正的CURSOR。

3. 如果CallInsertTruckService(string id, string code, string vinNumber, string licPlateNo) 签名是用[SqlProcedure()] 修饰的实际方法，那么您确实应该使用SqlString 而不是string。使用SqlString 参数的.Value 属性从每个参数中获取本机string 值。然后，您可以使用[SqlFacet()] 属性设置适当的大小，如下所示：

   [SqlFacet(MaxSize=24)] SqlString vinNumber
   

---

有关使用 SQLCLR 的更多信息，请参阅我在 SQL Server Central 上就该主题撰写的系列文章：Stairway to SQLCLR（需要免费注册才能阅读该站点上的内容）。