0%

[DotnetCore]ORM系列-SqlSugar:AOP篇

前提情要

前幾篇介紹完SqlSugar的應用後,這篇筆者要來實作SqlSugarAOP機制了,基本上就是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

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

結論

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

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

參考