2013年11月5日 星期二

初探 Entity Framework 6 - Intercepting Part.2

上一篇的最後有說到要將 Insert, Update, Delete 所執行的 SQL Command 內容透過 NLog 給紀錄在文字檔中,但我們所使用的 NLogCommandInterceptor 並沒有這樣的處理,所以這部份就需要我們自己動手來做,在這一篇文章裡就說明處理的過程。

 


回到 NLogCommandInterceptor 類別裡,有關 Insert, Update, Delete 都是屬於 NonQuery 的處理,所以我們可以在 NonQueryExecuted 方法裡進行修改,原本已經有執行一個 LogIfNonAsync 方法,目前已經不需要了,另外建立一個 LogNonQueryCommand 的方法來替代,而我們所要紀錄的內容有:SQL Command Text, Parameters, 執行所花費的時間。

 

Step.1

在 NLogCommandInterceptor 加入 Stopwatch 類別的欄位以及屬性,用來精確測量耗用的時間,

image

 

Step.2

原本在 NonQueryExecuted 方法裡是使用 LogIfError(),則改為使用 LogNonQueryCommand() 方法,這個方法是自己建立的 method,等一下再列出 Method 的詳細程式內容。

而為了要取得測量執行所耗用的時間,必須要先在 NonQueryExecuting 方法內的最後,需要先執行 Stopwatch.Restart()(停止時間間隔測量,並將耗用時間重設為零,然後開始測量耗用時間),接著在 NonQueryExecuted 方法裡的 LogNonQueryCommand 方法前要先執行 Stopwatch .Stop()(停止測量已耗用的時間)。

image

 

Stop.3

在 LogNonQueryCommand<TResult> 方法裡,我這邊只有針對沒有使用非同步處理的操作進行紀錄,另外假如已執行的 NonQuery 發生了 Exception,那麼就會去執行 LofIfError 方法。

以下是 LogNonQueryCommand 方法的程式內容,

private void LogNonQueryCommand<TResult>(
    DbCommand command,
    DbCommandInterceptionContext<TResult> interceptionContext)
{
    if (command == null)
    {
        throw new ArgumentNullException("command");
    }
    if (interceptionContext == null)
    {
        throw new ArgumentNullException("interceptionContext");
    }
 
    if (interceptionContext.Exception != null)
    {
        LogIfError(command, interceptionContext);
    }
    else
    {
        //只有針對不是非同步處理
        if (!interceptionContext.IsAsync)
        {
            string logContent = LogCommand(command, interceptionContext);
            Logger.Info(logContent);
        }
    }
}

最後會將取得的 NonQuery Command 內容與資訊透過 NLog 紀錄到文字檔裡。

接下來會有兩個方法,分別為 LogCommand 與 LogParameter,前者是截取 NonQuery Commnad 的內容以及執行耗費時間,後者是取得 NonQuery Commnad 所使用到的 Parameters 資料內容,這兩個方法內的程式是參考 Entity Framework 6 Source Code 裡的程式然後再做適度修改,

LogCommand<TResult>()

private string LogCommand<TResult>(
    DbCommand command,
    DbCommandInterceptionContext<TResult> interceptionContext)
{
    if (command == null)
    {
        throw new ArgumentNullException("command");
    }
    if (interceptionContext == null)
    {
        throw new ArgumentNullException("interceptionContext");
    }
 
    var commandText = command.CommandText ?? "<null>";
 
    if (!commandText.EndsWith(Environment.NewLine, StringComparison.Ordinal))
    {
        commandText = string.Concat(commandText, Environment.NewLine);
    }
 
    if (command.Parameters != null)
    {
        commandText = string.Concat(
            commandText, Environment.NewLine, 
            "Parameters: ", Environment.NewLine);
 
        foreach (var parameter in command.Parameters.OfType<DbParameter>())
        {
            commandText = string.Concat(
                commandText, 
                LogParameter(command, interceptionContext, parameter));
        }
    }
 
    //執行開始時間
    commandText = string.Concat(commandText, Environment.NewLine,
        "-- Executing at ", DateTimeOffset.Now.ToUniversalTime());
 
    //取得目前執行個體所測量的已耗用時間總和,以毫秒為單位
    commandText = string.Concat(commandText, Environment.NewLine,
        "-- Completed in ", Stopwatch.ElapsedMilliseconds, " ms");
 
    return commandText;
}

LogParameter<TResult>()

private string LogParameter<TResult>(
    DbCommand command,
    DbCommandInterceptionContext<TResult> interceptionContext,
    DbParameter parameter)
{
    if (command == null)
    {
        throw new ArgumentNullException("command");
    }
    if (interceptionContext == null)
    {
        throw new ArgumentNullException("interceptionContext");
    }
    if (parameter == null)
    {
        throw new ArgumentNullException("parameter");
    }
    
    // -- Name: [Value] (Type = {}, Direction = {}, IsNullable = {}, Size = {}, Precision = {} Scale = {})
    var builder = new StringBuilder();
    builder.Append("-- ")
        .Append(parameter.ParameterName)
        .Append(": '")
        .Append((parameter.Value == null || parameter.Value == DBNull.Value) ? "null" : parameter.Value)
        .Append("' (Type = ")
        .Append(parameter.DbType);
 
    if (parameter.Direction != ParameterDirection.Input)
    {
        builder.Append(", Direction = ").Append(parameter.Direction);
    }
 
    if (!parameter.IsNullable)
    {
        builder.Append(", IsNullable = false");
    }
 
    if (parameter.Size != 0)
    {
        builder.Append(", Size = ").Append(parameter.Size);
    }
 
    if (((IDbDataParameter)parameter).Precision != 0)
    {
        builder.Append(", Precision = ").Append(((IDbDataParameter)parameter).Precision);
    }
 
    if (((IDbDataParameter)parameter).Scale != 0)
    {
        builder.Append(", Scale = ").Append(((IDbDataParameter)parameter).Scale);
    }
 
    builder.Append(")").Append(Environment.NewLine);
 
    return builder.ToString();
}

 

Step.4

完成了 NLogCommandInterceptor 類別的程式修改與增加後,接著要到 NLog.config 增加 Info 等級的 target 與 rule,

target

image

rule

image

 

執行結果

這邊的執行結果就直接放上 Log 的內容讓大家看看,

SNAGHTMLfc3ef86

由上而下分別是 Insert, Update, Delete,

   1:   =========================================================================
   2:   DateTime:2013-11-04 01:17:26.8562 
   3:   Message:
   4:  INSERT [dbo].[Customers]([CustomerID], [CompanyName], [ContactName], [ContactTitle], [Address], [City], [Region], [PostalCode], [Country], [Phone], [Fax])
   5:  VALUES (@0, @1, @2, @3, @4, @5, @6, NULL, NULL, NULL, NULL)
   6:   
   7:  Parameters: 
   8:  -- @0: '1111' (Type = StringFixedLength, Size = 5)
   9:  -- @1: 'test' (Type = String, Size = 40)
  10:  -- @2: 'test' (Type = String, Size = 30)
  11:  -- @3: 'test' (Type = String, Size = 30)
  12:  -- @4: 'test' (Type = String, Size = 60)
  13:  -- @5: 'test' (Type = String, Size = 15)
  14:  -- @6: 'test' (Type = String, Size = 15)
  15:   
  16:  -- Executing at 2013/11/3 下午 05:17:25 +00:00
  17:  -- Completed in 721 ms 
  18:   =========================================================================
  19:           
  20:   =========================================================================
  21:   DateTime:2013-11-04 01:18:15.6149 
  22:   Message:
  23:  UPDATE [dbo].[Customers]
  24:  SET [CompanyName] = @0, [ContactName] = @1, [ContactTitle] = @2, [Address] = @3, [City] = @4, [Region] = @5, [PostalCode] = NULL, [Country] = NULL, [Phone] = NULL, [Fax] = NULL
  25:  WHERE ([CustomerID] = @6)
  26:   
  27:  Parameters: 
  28:  -- @0: '1111' (Type = String, Size = 40)
  29:  -- @1: 'test' (Type = String, Size = 30)
  30:  -- @2: 'test' (Type = String, Size = 30)
  31:  -- @3: 'test' (Type = String, Size = 60)
  32:  -- @4: 'test' (Type = String, Size = 15)
  33:  -- @5: 'test' (Type = String, Size = 15)
  34:  -- @6: 'test ' (Type = StringFixedLength, Size = 5)
  35:   
  36:  -- Executing at 2013/11/3 下午 05:18:15 +00:00
  37:  -- Completed in 54 ms 
  38:   =========================================================================
  39:           
  40:   =========================================================================
  41:   DateTime:2013-11-04 01:26:42.3864 
  42:   Message:
  43:  DELETE [dbo].[Customers]
  44:  WHERE ([CustomerID] = @0)
  45:   
  46:  Parameters: 
  47:  -- @0: '1111 ' (Type = StringFixedLength, Size = 5)
  48:   
  49:  -- Executing at 2013/11/3 下午 05:26:42 +00:00
  50:  -- Completed in 61 ms 
  51:   =========================================================================
  52:           

 


以上就是有關 Entity Framework 6 Interceptiing 的功能,並且使用 NLog 紀錄截取的內容,在以往要作到這樣的功能是需要透過第三方套件或是自己寫程式,Entity Framework 6 提供了這樣的新功能,對於有需要做到資料變更稽核紀錄的需求就能夠更加簡單了。

 

參考連結:

MSDN - Data Developer Center > Entity Framework > Logging and Intercepting Database Operations

CodePlex – Entity Framework

 

以上

沒有留言:

張貼留言

提醒

千萬不要使用 Google Talk (Hangouts) 或 Facebook 及時通訊與我聯繫、提問,因為會掉訊息甚至我是過了好幾天之後才發現到你曾經傳給我訊息過,請多多使用「詢問與建議」(在左邊,就在左邊),另外比較深入的問題討論,或是有牽涉到你實作程式碼的內容,不適合在留言板裡留言討論,請務必使用「詢問與建議」功能(可以夾帶檔案),謝謝。