如何追踪每一笔记录的来龙去脉：一个完整的Audit Logging解决方案[上篇]

一、提出问题

在开发一个企业级 应用的时候，尤其在一个涉及到敏感数据的应用，比如财务系统、物流系统，我们往往有这样的需求：对于数据库中每一笔数据的添加、修改和删除，都需要有一个明确的日志，以便我们可以追踪每一笔记录的来龙去脉——数据的更新是被谁、在什么时候执行的？该操作还涉及到哪些具体的Table？原来的数据是什么？新的数据又是什么？

本Blog的目的就是基于上面提出的要求设计一个Audit Logging的解决方案。 

二、分析问题

基于上面提出的要求，我们进行具体的分析：

A．如何确定Log的粒度？

对于一个企业级 应用，数据的每一项操作应该被纳入一个Transaction中以保证数据的完整性。所以Transaction可以看作是数据操作的基本单元，我们的解决方案是 以Transaction为单位的Log。

B．如何确定记录的信息？

正如一开始我们提出的要求，我们记录的不仅仅包括Transaction本身的一些基本信息，比如执行该操作的User，执行的时间等。由于一个Transaction会涉及到对多个相关Table中的一个或者多个记录的增、删、改的操作，所以下面一些信息也需要纳入我们的Logging范畴：Transaction涉及的Table，每条记录的数据的变化:对于Insert操作，需要记录添加的新记录的数据，对于Update操作，需要记录原来的数据和更新后的数据，而对于Delete操作，需要记录Delete之前的数据。

C．如何设计记录的数据结构？

基于我们提取出的需要进行Log的信息，我们为决绝方案设计了下面的数据结构:两个具有主子关系的Table。主表T_AUDIT_LOG记录了一个Transaction的基本的信息：Transaction的标识，执行的用户帐号和操作的具体时间，子表T_AUDIT_LOG_DETAIL则记录了Transaction涉及的每条记录数据改变相关的信息：该记录对应的Table名称，操作的类型和具体的数据的变化。T_AUDIT_LOG和T_AUDIT_LOG_DETAIL通过Transaction的唯一标识TRANSACTION_NO关联在一起。 

主表T_AUDIT_LOG的结构：

• TRANSACTION_NO[CHAR（36）]：一个GUID代表的字符串，唯一表示一个Transaction。
• OPERATION_DATE[DATETIME]：Transaction真正执行的时间（Filed name应该改为OPERATION_TIME才对）
• USER_ID [VARCHAR] ：执行该Transaction的用户帐号。

子表T_AUDIT_LOG_DETAIL的结构：

• AUDIT_DETAIL_ID（INT）：一个自增长的Field，用作该表的主键。
• TRANSACTION_NO [CHAR（36）] ：同主表T_AUDIT_LOG的TRANSACTION_NO字段，Transaction的唯一标识，一个GUID。
• TABLE_NAME [VARCHAR] ：操作涉及的具体的Table的名称。
• OPERATION_TYPE [VARCHAR] ：操作的类型——Insert，Update，Delete。
• DATA_CHANGE [XML] ：该字段采用了SQL Server 2005新的数据类型——XML，用于存储操作引起的数据的改变。<before>Element封装了Update 操作之前的数据，其中每个XML attribute代表的是对用的Filed，<after>包含的则是Update执行之后的数据。这是Update操作对应的XML schema，如果操作对应的是向某个表中Insert一个记录，则只有封装了新添加记录数据的<after> element，同样的Delete操作对应的XML只有包含被Delete记录的<before> Element。

For Update

<dataChange>
  <before order_id="30" order_date="Apr 21 2007 12:00AM" supplier="HP" />
  <after order_id="30" order_date="Jan  1 2005 12:00AM" supplier="Dell Corporation" />
</dataChange>

For Insert

<dataChange>  
<after order_id="30" order_date="Jan  1 2005 12:00AM" supplier="Dell Corporation" />
</dataChange>

For Delete

<dataChange>
  <before order_id="30" order_date="Apr 21 2007 12:00AM" supplier="HP" />
</dataChange>

D．如何添加Log记录？

从T_AUDIT_LOG_DETAIL的结构上可以很清楚地看出，该表记录的是基于某个具体的Table的每个记录数据变化。所以我们会首先想到的是通过Trigger来添加这些Logging数据——当完成对相关Table的增、删、改操作后，通过出发我们为Audit Logging编写的Trigger来自动添加这些信息。所以我的这个Audit Logging的解决方案是一个基于Trigger的解决方案，我将在下面一节中讲述如何编写这个Trigger。由于我们的Logging数据表采用的是一个具有Parent-Child关系的两个Table，在通过Trigger为子表T_AUDIT_LOG_DETAIL添加Log记录之前，我们必须保证主表T_AUDIT_LOG中包含相应的记录，所以在进行与逻辑相关的数据操作之前，我们必须在把Log的总体信息插入T_AUDIT_LOG之中。

E．如何保证Logging操作和实际的操作纳入同一个Transaction中？

由于我们实际的商业逻辑的数据操作是一个基于Database的操作，而我们的Audit Logging也是一个基于Database的操作。而Audit Logging是基于这个具体商业逻辑的数据操作的。所以为了使用Logging的数据能够100%地反映真实执行了的数据操作，Logging操作和实际的数据操作应该纳入同一个Transaction中，避免造成Audit Logging记录一个执行失败的操作，或者数据操作执行成功而Logging操作执行失败。

F．权衡利弊

到现在为止，这个解决方案在功能上能够成功解决我们开篇提出的Logging要求，但是他在下面两个方面引起的不足必须引起足够的重视，不然会彻底毁掉你的应用。

• 引起T_AUDIT_LOG_DETAIL表中的数据的急剧上升：由于对于需要进行Audit Logging的每个Table，它的每个记录的操作都会在T_AUDIT_LOG_DETAIL增加一条记录，如果这样Table，或者对这样的Table的操作过于频繁，将会造成该表中的记录急剧上升，近而影响整个应用的性能。
• 性能问题：由于对需要进行Audit Logging的Table的每项操作都会出发Trigger，这会在一定程度影响数据操作的性能。

通过对上面的分析，我们大体知道整个解决方案的整体思路，现在我们来具体地在编程方面来进一步实现这个解决方案。

三、 解决方案

A．表的结构设计

对于一个涉及到敏感数据的企业级应用，对数据表的设计很重要，为了能够追踪每一笔数据的来龙去脉，能够确定每一笔记录被谁创建？什么时候创建？被谁最后一次修改？什么时候作的修改？如何处理并发操作？如何进行我们的Audit Logging？基于这些需求，我对每一个Table添加了下面7个Common 的字段：

• CREATED_BY（VARCHAR）：创建该记录的User ID。
• CREATED_ON（DATETIME）：纪录的创建时间。
• LAST_UPDATED_BY（VARCHAR）：记录最后一次被修改对应的User ID。
• LAST_UPDATED_ON（DATETIME）：记录最后一次修改的时间。
• VERSION_NO（TIMESTAMP）：表明该记录的版本号，用于并发操作。
• TRANSACTION_NO（CHAR（36））：该记录最后一次修改的对用的Transaction的ID，也就是我们今天进行Audit Logging对应的那个Transaction的ID。
• NEED_AUDIT（bit）：这个将在后面的部分介绍它的用途。

当我们进行任何涉及到数据库的操作，为了保证数据的完整性，我们会把所有的操作纳入一个Transaction之中。为了有利于Auditing，我们在开始 这个Transaction之前，会生成一个基于GUID的Transaction No, 并把它更新到该Transaction涉及的每个记录的TRANSACTION_NO字段。如果某条记录是新添加的，那么我们会把CREATED_BY和LAST_UPDATED_BY赋值为当前的User，把CREATED_ON和LAST_UPDATED_ON赋值为当前的时间。如果我们要修改或者删除某条记录，我们通过获取记录的VERSION_NO和数据库中对应的数据进行比较来判断该记录时候在被当前Session取出后又被别的User修改了，从而有效地处理并发操作。

B． 整个数据处理流程

ADO.NET为我们在.NET平台下提供了简单而直接的数据操作机制。此外，通过Dataset、DataAdapter、DbCommand等一系列的Component，实现我们常用的离线的方式来操作数据库：我们通过DataAdapter获取数据填充到我们的Dataset对象，并断开Db Connection。我们通过Dataset来构建一个内存中的数据库来mapping真正Db中的数据结构，最终我们通过DataAdapter把对Dataset中的数据更新递交到Db中。我们的Audit Logging就以这样一种机制来介绍。我们通过这种离线操作模式来介绍我们的整个Log的操作流程，当然这个Audit Logging解决方案同样适合基于Connection的数据操作。

正如上图所描述的，我们首先从Db中获取数据并填充到Dataset中，然后我们把 Audit Log的基本的数据添加到一个Audit Log Dataset中，并生成（对应T_AUDIT_LOG表），一个Transaction的一个ID，我们称之为Transaction No，然后我们根据我们具体的业务逻辑来对我们用来承载获取数据的Dataset作相应的修改，并把我们生成的Transaction更新到该Dataset每个需要更新的Data Row中。然后我们把基于商业逻辑的更新和添加的Log数据向Db提交，所有的这些操作被纳入到一个单独Transaction中。当这些更新通过最终调用SQL或者Stored procedure更新到Db中后，对应的Trigger被触发，基于某个Table的数据改变的信息被添加到T_AUDIT_LOG_DETAIL中。

C． Programming

上面我们通过文字介绍了Audit logging 的整个流程，我们现在已我们最擅长的编程的角度来进一步了解这个过程。

首先我们定义了一个AuditLoggingDataSet的强类型的Dataset，该Dataset包含一个Table：T_AUDIT_LOG，映射DB中的同名T_AUDIT_LOG表。

然后我们定义了一个专门用于Audit Logging操作的Helper类：AuditLoggingHelper
该Helper包含连个Public成员，一个Property：AuditLoggingData，返回对应的Log数据。一个方法AuditLog，添加Log信息并以GUID的形式返回一个Transaction No。

using System;
using System.Collections.Generic;
using System.Text;

namespace Artech.AuditLogging.ConsoleApp
{
    public class AuditLoggingHelper
    {
        private AuditLoggingDataSet _auditLoggingData;

        /**//// <summary>
        /// A strongly typed dataset to used to store the general auditoing inforamtion. 
        /// </summary>
        public AuditLoggingDataSet AuditLoggingData
        {
            get { return _auditLoggingData; }
            set { _auditLoggingData = value; }
        }

        /**//// <summary>
        /// Log the general auditoing information according with the current transaction.
        /// </summary>
        /// <returns>A guid which identifies uniquely a transaction</returns>
        public Guid AuditLog()
        {
            if (this._auditLoggingData == null)
            {
                this._auditLoggingData = new AuditLoggingDataSet();
            }

            Guid transactionNo = Guid.NewGuid();
            AuditLoggingDataSet.T_AUDIT_LOGRow auditRow= this._auditLoggingData.T_AUDIT_LOG.NewT_AUDIT_LOGRow();

            auditRow.BeginEdit();
            auditRow.TRANSACTION_NO = transactionNo.ToString();
            //TODO: The user id is generally the account of the current login user.
            auditRow.USER_ID = "testUser";
            auditRow.OPERATION_DATE = DateTime.Now;
            auditRow.EndEdit();

            this._auditLoggingData.T_AUDIT_LOG.AddT_AUDIT_LOGRow(auditRow);

            return transactionNo;
        }
    }
}

我还定义了一个专门定义了用于Data Access操作的DataAccessHelper的另一个Helper类。这个Helper类帮助我以一种简单的方式向Db获取、提交数据。我将现在下面一节中简单介绍这个DataAccessHelper。

现在我们简单地来模拟这样一个场景：我们有一个简单的处理Order的应用, 从Db中获取某个Order ID的Order信息，对获取的数据进行相应修改后被最终被提交到Db中。

我们简化了Order数据的复杂度，假设DB中对应的Table如下，通过这些是我们Dataset的结构，我将在下面一节已Sample的形式来一步一步来介绍这个场景，现在我们这些简单地通过程序来了解整个处理的流程。

我们现在来看我们的code:

using System;
using System.Collections.Generic;
using System.Text;
using System.Data;

namespace Artech.AuditLogging.ConsoleApp
{
    class Program
    {
        static string USER_ID = "testUser";

        static void Main(string[] args)
        {
            UpdateOrderData();
        }

        static void UpdateCommonField(DataRow row)
        {
            row["LAST_UPDATED_BY"] = USER_ID;
            row["LAST_UPDATED_ON"] = DateTime.Now;
            if (row.RowState == DataRowState.Detached || row.RowState == DataRowState.Added)
            {
                row["CREATED_BY"] = USER_ID;
                row["CREATED_ON"] = DateTime.Now;
            }
        }  

        static OrderDataSet GetAllOrderData()
        {
            OrderDataSet orderData = new OrderDataSet();
            using (DataAccessHelper dataAccessHelper = new DataAccessHelper())
            {
                orderData.EnforceConstraints = false;
                dataAccessHelper.FillData(orderData.T_ORDER, CommandType.Text, "SELECT * FROM dbo.T_ORDER", new Dictionary<string, object>());
                dataAccessHelper.FillData(orderData.T_ORDER_DETAIL, CommandType.Text, "SELECT * FROM dbo.T_ORDER_DETAIL", new Dictionary<string, object>());
                orderData.EnforceConstraints = true;                
            }

            return orderData;
        }

        static void UpdateOrderData()
        {
            OrderDataSet orderData = GetAllOrderData();
            AuditLoggingHelper auditLoggingHelper = new AuditLoggingHelper();
            Guid transactionNo = auditLoggingHelper.AuditLog();

     OrderDataSet.T_ORDERRow orderRow = orderData.T_ORDER[0];
            orderRow.ORDER_DATE = new DateTime(2005, 1, 1);
            orderRow.SUPPLIER = "Dell Corporation";
            orderRow.TRANSACTION_NO  = transactionNo.ToString();
            UpdateCommonField(orderRow);
    

            using (DataAccessHelper dataAccessHelper = new DataAccessHelper())
            {                
                dataAccessHelper.BeginTransaction();
                try
                {
                    dataAccessHelper.UpdateData(auditLoggingHelper.AuditLoggingData.T_AUDIT_LOG);
                    dataAccessHelper.UpdateData(orderData.T_ORDER);
                    dataAccessHelper.UpdateData(orderData.T_ORDER_DETAIL);
                    dataAccessHelper.Commit();
                }
                catch (Exception ex)
                {
                    dataAccessHelper.Rollback();
                    Console.WriteLine(ex.Message);
                }
            }            
        }
    }
}

这个程序执行的流程很简单，这里应该不需要再作进一步的说明。通过向Db提交auditLoggingHelper.AuditLoggingData.T_AUDIT_LOG，整个Audit Logging实际上只做了一半。通过前面对Logging数据的介绍，我们知道需要Log 是基于两张表：T_AUDIT_LOG和T_AUDIT_LOG_DETAIL.我现在仅仅添加了T_AUDIT_LOG这个主表的数据，具体的Log信息实际上存储在T_AUDIT_LOG_DETAIL这个子表中，而这个表中的数据是通过Trigger写入的。我们现在就来看看，这个Trigger如何写。 

D．定义Trigger

我们已表T_Order为例，由于对它的添加、修改和删除都需要把 对应的数据的改变记录到T_AUDIT_LOG_DETAIL中，我们需要为这3种操作类型定义Trigger。

For Insert：'tr_order_i'

IF EXISTS (SELECT * FROM sysobjects WHERE type = 'TR' AND name = 'tr_order_i')
    BEGIN
        DROP  Trigger tr_order_i
    END
GO

CREATE Trigger tr_order_i ON dbo.T_ORDER 
AFTER INSERT
AS
IF UPDATE(VERSION_NO)
BEGIN
        INSERT [dbo].[T_AUDIT_LOG_DETAIL]
                ([TRANSACTION_NO]
                ,[TABLE_NAME]
                ,[OPERATION_TYPE]
                ,[DATA_CHANGE])                
        SELECT INSERTED.TRANSACTION_NO
                , 'T_ORDER'
                ,'Insert'
                ,'<dataChange> <after order_id ="'+CONVERT(VARCHAR,INSERTED.ORDER_ID)+'"' +
                ' order_date="' +CONVERT(VARCHAR,INSERTED.ORDER_DATE) + '"' +
                ' supplier="'+INSERTED.SUPPLIER +'"/></dataChange>'
        FROM  INSERTED 
        
END  

GO

For Update：'tr_order_u'

IF EXISTS (SELECT * FROM sysobjects WHERE type = 'TR' AND name = 'tr_order_u')
    BEGIN
        DROP  Trigger tr_order_u
    END
GO

CREATE Trigger tr_order_u ON dbo.T_ORDER 
AFTER UPDATE
AS
IF UPDATE(VERSION_NO)
BEGIN
        INSERT [dbo].[T_AUDIT_LOG_DETAIL]
                ([TRANSACTION_NO]
                ,[TABLE_NAME]
                ,[OPERATION_TYPE]
                ,[DATA_CHANGE])
        SELECT INSERTED.TRANSACTION_NO
                , 'T_ORDER'
                ,'Update'
                ,'<dataChange> <before order_id ="'+CONVERT(VARCHAR,DELETED.ORDER_ID)+'"' +
                ' order_date="' +CONVERT(VARCHAR,DELETED.ORDER_DATE) + '"' +
                ' supplier="'+DELETED.SUPPLIER +'"/>' +
                '<after order_id ="'+CONVERT(VARCHAR,INSERTED.ORDER_ID)+'"' +
                ' order_date="' +CONVERT(VARCHAR,INSERTED.ORDER_DATE) + '"' +
                ' supplier="'+INSERTED.SUPPLIER +'"/></dataChange>'
        FROM DELETED INNER JOIN INSERTED ON
        DELETED.ORDER_ID = INSERTED.ORDER_ID           
        WHERE INSERTED.NEED_AUDIT  = 1    
        
END    

GO

我知道对于一个Trigger来说，我们可以通过两个表INSERTED和DELETED获取原来的数据和当前的数据。所以我们可以通过INSERTED.TRANSACTION_NO获取对应的Transaction No。这个对于Insert和Update操作没有任何问题，但是对于Delete操作，INSERTED表中没有数据，我们如何获取这个必须的Transaction No呢？我们的做法的是，在数据被真正被Delete之前，先对它进行Update操作，把Transaction No赋值给它的TRANSACTION_NO字段。那么在真正触发Delete Trigger的时候，就可以通过 DELETED. TRANSACTION_NO来获得这个Transaction No。但是这又带来了一个新的问题，我们通过为一个即将被Delete的记录修改Transaction No的时候，他会触发我们上面定义的Update Trigger，那么一些错误的信息会添加到T_AUDIT_LOG_DETAIL之中，这显然是不允许的。如何来解决这个问题呢？这就要借助要的NEED_AUDIT 这个字段了。这个字段的默认值为1（true），在Delete之前我们不但修改TRANSACTION_NO，我们还将NEED_AUDIT 字段赋为0。那么Update trigger就会根据这个字段判断该Update操作是否是真正意义上的Update。这也是我们在上面的Trigger中加入了一个条件WHERE INSERTED.NEED_AUDIT = 1的原因。

下面我们来看Delete Trigger：tr_order_d

IF EXISTS (SELECT * FROM sysobjects WHERE type = 'TR' AND name = 'tr_order_d')
    BEGIN
        DROP  Trigger tr_order_d
    END
GO

CREATE Trigger tr_order_d ON dbo.T_ORDER 
AFTER DELETE
AS

BEGIN        
        
        INSERT [dbo].[T_AUDIT_LOG_DETAIL]
                ([TRANSACTION_NO]
                ,[TABLE_NAME]
                ,[OPERATION_TYPE]
                ,[DATA_CHANGE])
                
        SELECT TRANSACTION_NO
                , 'T_ORDER'
                ,'Delete'
                ,'<dataChange> <before order_id ="'+CONVERT(VARCHAR,DELETED.ORDER_ID)+'"' +
                ' order_date="' +CONVERT(VARCHAR,DELETED.ORDER_DATE) + '"' +
                ' supplier="'+DELETED.SUPPLIER +'"/></dataChange>' 
        FROM DELETED
END
GO

[原创] 如何追踪每一笔记录的来龙去脉：一个完整的Audit Logging解决方案—Part II