Eugene's Blog
0%

[DotnetCore]ORM系列-SqlSugar:AOP篇

發表於 更新於 分類於 ， 閱讀次數：
7.1k 13 分鐘

前情提要

前幾篇介紹完SqlSugar的應用後，這篇筆者要來實作SqlSugar的AOP機制了，基本上就是Sql執行前後，或者發生Error後的事件，應有盡有，剛好符合筆者公司的要求，每個執行的作業出錯時要記錄下來，尤其是出錯時，最好能記錄到完整的SQL指令，釐清問題上更加有幫助，筆者介紹的幾個ORM框架通常都有類似的解決方案，表示這是大家都需要的功能

內容

SqlSugar用法請參考筆者的[DotnetCore]ORM系列-SqlSugar:入門篇，筆者這邊就沿用該範例，再回憶使用方式

安裝套件

1
2
3
dotnet add package sqlSugarCore
# 若資料庫為MySql，要多安裝MySqlConnector
dotnet add package MySqlConnector

註冊SqlSugar

於Startup中註冊，以利Service層時注入使用SqlSugar實體

1
2
3
4
5
6
7
8
9
10
services.AddTransient(provider =>
{
    return new SqlSugarClient(new ConnectionConfig()
    {
        DbType = DbType.SqlServer,
        ConnectionString = {ConnectionString},// 換成真實的連結字串
        InitKeyType = InitKeyType.Attribute,
        IsAutoCloseConnection = true // 表示Service使用完畢Dispose時連線自動關閉
    });
});

新增Interceptor

Interceptor部份，必須依賴於SqlSugar實體，針對SqlSugar實體，加註一些AOP機制，SqlSugar提供四個事件觸發Method讓我們可以加註宣告

  • SQL執行前
  • SQL執行完成後
  • SQL發生Error時
  • SQL執行前可修改SQL指令及置換參數

另外還有

  • 數據過濾器(筆者會另外寫一篇)
  • 資料差異事件監聽(目前筆者沒有這個需求，到時有使用情境時再來寫)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
services.AddTransient(provider =>
{
    var db = new SqlSugarClient(new ConnectionConfig()
    {
        DbType = DbType.SqlServer,
        ConnectionString = {ConnectionString},// 換成真實的連結字串
        InitKeyType = InitKeyType.Attribute,
        IsAutoCloseConnection = true,
    });
    //SQL執行完成後觸發
    db.Aop.OnLogExecuted = (sql, pars) => 
    {
        //執行完了可以輸出SQL執行時間 (OnLogExecutedDelegate) 
        Console.Write("time:" + db.Ado.SqlExecutionTime.ToString()); 
    };
    //SQL執行前觸發
    db.Aop.OnLogExecuting = (sql, pars) => 
    {
        
    };
    //SQL發生Error時觸發
    db.Aop.OnError = (exp) =>
    {
        //exp.sql 這樣可以拿到原始的完整SQL            
    };
    //可以修改SQL和參數的值
    db.Aop.OnExecutingChangeSql = (sql, pars) => 
    {
        //sql=newsql
        //foreach(var p in pars) //修改
        return new KeyValuePair<string, SugarParameter[]>(sql,pars);
    };
    return db;
});

實際執行

筆者就用NLog以文字檔的方式記錄一下各個事件發生的順序以及內容物，請參考筆者的[DotnetCore]NLog使用，筆者這邊為demo，nlog.config中只設定了file這條rule，套上nlog之後的語法

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
//SQL執行完成後觸發
db.Aop.OnLogExecuted = (sql, pars) =>
{
    //執行完了可以輸出SQL執行時間 (OnLogExecutedDelegate) 
    _logger.Info("[OnLogExecuted]Executed Time:" + db.Ado.SqlExecutionTime.ToString());
};
//SQL執行前觸發
db.Aop.OnLogExecuting = (sql, pars) =>
{
    _logger.Info($"[OnLogExecuting]Executing SQL: {sql}");
};
//SQL發生Error時觸發
db.Aop.OnError = (exp) =>
{
    //exp.sql 這樣可以拿到原始的完整SQL   
		_logger.Info($"[OnError]Sql:{exp.Sql}");
    _logger.Info($"[OnError]Exeception:{exp}");
};
//可以修改SQL和參數的值
db.Aop.OnExecutingChangeSql = (sql, pars) =>
{
    //sql=newsql
    _logger.Info($"[OnExecutingChangeSql]{sql}");
    foreach(var p in pars) //修改
    {
        _logger.Info($"[OnExecutingChangeSql]{p.ParameterName}:{p.Value.ToString()}");
    }
    return new KeyValuePair<string, SugarParameter[]>(sql, pars);
};

執行結果

正常執行作業

筆者這邊使用[DotnetCore]ORM系列-SqlSugar:查詢篇1那篇文章的操作，跟著筆者看一下整個Interceptor的生命週期吧，先做一個正常的查詢，取得前十筆資料

http://localhost:5000/api/Customer/take/10

接著看一下Log文字檔案

1
2
3
2021-11-12 09:40:37.9649 INFO [OnExecutingChangeSql]SELECT `CustomerNumber`,`CustomerName`,`ContactLastName`,`ContactFirstName`,`Phone`,`AddressLine1`,`AddressLine2`,`City`,`State`,`PostalCode`,`Country`,`SalesRepEmployeeNumber`,`CreditLimit` FROM `Customers`     LIMIT 0,10
2021-11-12 09:40:37.9707 INFO [OnLogExecuting]Executing SQL: SELECT `CustomerNumber`,`CustomerName`,`ContactLastName`,`ContactFirstName`,`Phone`,`AddressLine1`,`AddressLine2`,`City`,`State`,`PostalCode`,`Country`,`SalesRepEmployeeNumber`,`CreditLimit` FROM `Customers`     LIMIT 0,10
2021-11-12 09:40:38.4760 INFO [OnLogExecuted]Executed Time:00:00:00.5043520

可以看出SqlSugar的Interceptor的順序依序為

  • OnExecutingChangeSql
  • OnLogExecuting
  • OnLogExecuted

錯誤執行作業

筆者這邊在寫一個錯誤的語法，執行一個不存在的Stored Procedure，來模擬觸發OnError事件

1
2
3
4
5
6
7
8
9
10
11
/// <summary>
/// 模擬製作Error觸發
/// </summary>
/// <returns></returns>
[HttpPost("error")]
public IActionResult ErrorSimulate()
{
    _db.Ado.SqlQuery<Sugar.customers>("CALL SP1 (@CustomerName, @Country)"
        , new{ CustomerName = "Signal Gift Stores", Country = "USA" });
    return Ok("");
}

以上節寫法，於OnError事件中只記錄下Sql是不足夠的，需要將Sql對應的Parameter也要一併紀錄下來，才可以事後驗證追蹤問題，筆者實驗後發現OnError事件中的DBParameter藏在exp.parametres中，因parameter可能是多個，因此是以List的形式存在著，筆者仿照對應的結構建立一個Class

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
public class ErrorDBParameter
{
    public int _Size { get; set; }
    public bool IsRefCursor { get; set; }
    public int DbType { get; set; }
    public int Direction { get; set; }
    public bool IsNullable { get; set; }
    public string ParameterName { get; set; }
    public int Size { get; set; }
    public object SourceColumn { get; set; }
    public bool SourceColumnNullMapping { get; set; }
    public object UdtTypeName { get; set; }
    public string Value { get; set; }
    public object TempDate { get; set; }
    public int SourceVersion { get; set; }
    public object TypeName { get; set; }
    public bool IsJson { get; set; }
    public bool IsArray { get; set; }
    public int Precision { get; set; }
    public int Scale { get; set; }
}

接著改寫OnError事件中的Log記錄邏輯

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
//SQL發生Error時觸發
db.Aop.OnError = (exp) =>
{
    //exp.sql 這樣可以拿到原始的完整SQL   
    _logger.Info($"[OnError]Sql:{exp.Sql}");
    var parameters = JsonConvert.SerializeObject(exp.Parametres);
    if (!string.IsNullOrEmpty(parameters))
    {
        var paraList = JsonConvert.DeserializeObject<List<Models.ErrorDBParameter>>(parameters);
        foreach (var p in paraList)
        {
            _logger.Info($"[OnError:Paramater]{p.ParameterName}:{p.Value}");
        }
    }
    _logger.Info($"[OnError]Exeception:{exp.GetBaseException()}");
};

筆者這邊為防呆，有些Sql可能是沒有Parameter的，這樣勢必exp.Parametres是空值，因此使用JsonConvert.SerializeObject的方式轉成字串，判斷其是否為null，再進行Deserialize的作業，使用上面建立好的Class去反序列化，紀錄部分在乎的是ParameterName及其Value，將它們記錄下來，最後Exception部份，直接取原始的Exception，透過exp.GetBaseException，這樣的紀錄資訊已足夠追蹤問題。

最後執行Postman，看一下Log文字檔案紀錄

1
2
3
4
5
6
7
8
9
// url: http://localhost:5000/api/Customer/error
2021-11-12 10:25:07.0449 INFO [OnExecutingChangeSql]Exec SP1 @CustomerName, @Country
2021-11-12 10:25:07.0491 INFO [OnExecutingChangeSql]@CustomerName:Signal Gift Stores
2021-11-12 10:25:07.0491 INFO [OnExecutingChangeSql]@Country:USA
2021-11-12 10:25:07.0510 INFO [OnLogExecuting]Executing SQL: Exec SP1 @CustomerName, @Country
2021-11-12 10:25:07.5917 INFO [OnError]Sql:Exec SP1 @CustomerName, @Country
2021-11-12 10:25:07.8539 INFO [OnError:Paramater]@CustomerName:Signal Gift Stores
2021-11-12 10:25:07.8539 INFO [OnError:Paramater]@Country:USA
2021-11-12 10:25:07.8553 INFO [OnError]Exeception:SqlSugar.SqlSugarException: PROCEDURE classicmodels.SP1 does not exist

可以看出執行錯誤時的Interceptor順序為

  • OnExecutingChangeSql
  • OnLogExecuting
  • OnError

從上述兩種情境執行結果可以看出OnExecuted及OnError是依照執行正確與否擇一觸發。

結論

筆者在公司環境混用EFCore及Dapper，為了SQL Log花了一番功夫，也不是很完整的Solution，筆者這邊是用自定義的SqlConnection及DBCommand等方式完成，所以是override的概念來擴充，本身不會參與執行階段，變成原本的需求是Sql出現Error時才需記錄其完整SQL指令部份就沒有百分之百達到，依筆者的作法，所有的Sql指令都會紀錄，但出現Error後紀錄又是另一個事件GlobalErrorHanlder，因此Log紀錄會分化成兩筆資料，實際追蹤上是需要一點時間查找。

反觀SqlSugar，可以使用Lambda操作(Insert, Update)，也可以執行原生SQL，Interceptor事件也是包得好好的，依筆者公司的需求，只要實作OnError事件即可，是個完美解決方案，筆者會花些時間在公司導入SqlSugar，以取代EFCore、Dapper混用效果。

參考

相關文章