触发器中执行的方法发生异常时日志不持久化

Logging not Persisting When Exception Occurs in Method Executed in a Trigger

我整天都被这个问题困住了,似乎无法在网上找到任何指向我可能导致它的原因。

我在 Logger class 中有以下日志记录方法和调用记录器的以下代码。当没有异常发生时,所有日志语句都可以正常工作,但是当发生异常时,日志语句根本不会 运行(但是它们会从 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 块中的语句外都是成功的。如果抛出异常,则其中 none 个成功。对于它们中的大多数,无论是否存在异常,值都完全相同,所以我知道传递的值不是问题。我在想一些奇怪的事情正在发生,导致回滚或其他事情,但我没有在这里使用事务或任何东西。这个 DLL 的最后一件事是 运行 通过 SQL CLR,这就是为什么我使用 "context connection=true" 作为我的连接字符串。

提前致谢。

编辑:

我尝试将以下内容添加为我的连接字符串,但在尝试 .Open the connection now 时出现异常 "Transaction context in use by another session"。我认为这与我通过触发器调用此 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

这里的主要问题是 SQLCLR 存储过程是从触发器中调用的。触发器总是 运行s 在事务的上下文中(将其绑定到启动触发器的 DML 操作)。触发器还隐式地将 XACT_ABORT 设置为 ON,如果发生 any 错误,则取消事务。这就是为什么 none 的日志语句在抛出异常时仍然存在:事务是自动回滚的,它会带走在同一会话中所做的任何更改,包括日志语句(因为 Context Connection 是同一个Session),以及原来的DML语句。

你有三个相当简单的选项,尽管它们会给你带来一个整体架构问题,或者一个不那么困难但需要更多工作的选项,它可以解决眼前的问题以及更大的问题架构问题。一、三个简单选项:

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

  2. 您可以不理会 SET XACT_ABORT 并使用常规/外部连接到 SQL 服务器。常规连接将是一个完全独立的连接和会话,因此它可以独立于事务运行。与 SET XACT_ABORT OFF; 选项不同,这将允许触发器运行 "normally"(即任何错误都会回滚触发器中本机进行的任何更改以及原始 DML 语句),同时仍然允许日志记录 INSERT 语句持久化(因为它们是在本地事务之外进行的)。

    您已经在调用 Web 服务,因此程序集已经拥有必要的权限来执行此操作而无需进行任何其他更改。您只需要使用适当的 connection string (您的语法中有一些错误),可能类似于:

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

    "Enlist=False;" 部分(滚动到最右边)非常重要:没有它您将继续获得“另一个会话正在使用的事务上下文”错误。

  3. 如果您想坚持使用 Context Connection(速度稍快)并允许 Web 服务 之外的任何错误回滚原始 DML 语句 所有日志语句,同时忽略来自 Web 服务的错​​误,甚至是来自日志 INSERT 语句的错误,那么您可以简单地不重新抛出CallInsertTruckServicecatch 块中的异常。您可以改为设置一个变量来指示 return 代码。由于这是一个存储过程,它可以 return SqlInt32 而不是 void。然后您可以通过声明一个 INT 变量并将其包含在 EXEC 调用中来获取该值,如下所示:

    EXEC @ReturnCode = dbo.SLX_CallInsertTruckService ...;
    

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

话虽这么说,无论你选择哪一个,你仍然面临两个相当大的问题:

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

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

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

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

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

如果有永远不会处理的记录,那么您可以将 RetryCount 列添加到队列 table,将其默认为 0,并且在 Web 服务出现错误时,递增 RetryCount 而不是删除该行。然后您可以更新 "get entry to process" SELECT 查询以包含 WHERE RetryCount < 5 或您要设置的任何限制。


这里有几个问题,影响程度不同:

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

  2. 仅供参考,与使用实际的 CURSOR 相比,WHILE (@counter < @maxCounter) 循环效率低下且容易出错。我会摆脱 @tmp Table 变量和 @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(免费注册需要阅读该网站上的内容)。