EntityFramework之監聽者判斷SQL性能指標

前言

當我們利用EF這個ORM框架時，我們可能會利用LINQ或者原生的SQL語句來進行數據操作，此時我們無法確定我們的代碼是否會給數據庫帶來一定的負載，當給數據庫帶來一定的壓力時，由於項目中對數據進行相應的操作實在是太多，我們無法准確的去進行定位，又或者我們不是專業的DBA，無法准確的去分析SQL性能的優劣，此時該怎么辦呢？我們完全不需要DBA，我們可以通過相應的操作來判斷一段SQL代碼的好壞，這就是我們本節需要講的內容，利用EF中監聽者來判斷SQL性能，在之前系列中也有提到，可以參考之前系列。我們進入主題。

DbCommandInterceptor

不用講從字面意思我們就能立馬明白大概是【監聽命令】，我們看下該類，如下：

我們無需多加細看，看這幾個虛方法我們馬上就能明白和我們之前猜測的一致，就是進行數據庫操作的SQL命令。在這個類中有一個重要的類那就是 DbCommandInterceptionContext ，我們姑且叫做監聽SQL命令的上下文吧，我們再看這個類中包含什么。如下：

在這個類中有一個重要的屬性 UserState ，哦，意思是用戶狀態，根據摘要信息得知，我們可以設置我們進行操作的相關信息，同時還是個object類型，看來是利於對象之間的轉換而給。

接下來進入主題，我們如何去判斷SQL性能指標呢？答案：我們檢索出執行SQL時以及執行SQL完成后的消耗時間即可。

SQL性能判斷指標

那么問題來了，我們該如何正確這個時間呢？此問題又可以細分為兩個步驟。

（1）如何知道SQL命令是正在執行時以及執行完成呢？

（2）知道了之后我們又如何設置以及獲取時間呢？

我們一一來划分，首先我建立一個類 SQLProfiler ，而此類肯定是繼承於 DbCommandInterceptor ，所以代碼就變成了這樣。

    public class SQLProfiler : DbCommandInterceptor
    {
        public override void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
        {
            Executing(interceptionContext);
            base.ReaderExecuting(command, interceptionContext);
        }

        public override void ReaderExecuted(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
        {
            Executed(command, interceptionContext);
            base.ReaderExecuted(command, interceptionContext);
        }

        public override void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
        {
            Executing(interceptionContext);
            base.NonQueryExecuting(command, interceptionContext);
        }

        public override void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
        {
            Executed(command, interceptionContext);
            base.NonQueryExecuted(command, interceptionContext);
        }

        public override void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
        {
            Executing(interceptionContext);
            base.ScalarExecuting(command, interceptionContext);
        }

        public override void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
        {
            Executed(command, interceptionContext);
            base.ScalarExecuted(command, interceptionContext);
        }
}

貌似發現了什么，好像方法參數都是什么DbCommand和DbCommandInterCeptionContext，既然這樣，我們依樣畫葫蘆諾，為了從執行SQL命令開始，我們此時從這里開始計時，將計時對象給UserState即可，於是就有了下面的代碼。

        private void Executing<T>(DbCommandInterceptionContext<T> interceptionContext)
        {
            var timer = new Stopwatch();
            interceptionContext.UserState = timer;
            timer.Start();
        }

此時應該就明朗了，我們在執行完成后來獲取該計時對象並利用是否出現異常和我們指定設置的時間來判斷其最終所花費的時間。執行完成后代碼如下：

        private void Executed<T>(DbCommand command, DbCommandInterceptionContext<T> interceptionContext)
        {
            var timer = (Stopwatch)interceptionContext.UserState;
            timer.Stop();

            if (interceptionContext.Exception != null)
            {
                File.AppendAllLines(
                    _logFile,
                    new string[]
                {
                "錯誤SQL語句",
                interceptionContext.Exception.Message,
                command.CommandText,
                Environment.StackTrace,
                string.Empty,
                string.Empty,
                });
            }
            else if (timer.ElapsedMilliseconds >= _executionTime)
            {
                File.AppendAllLines(
                    _logFile,
                    new string[]
                {
                string.Format("耗時SQL語句({0}ms)",timer.ElapsedMilliseconds),
                command.CommandText,
                Environment.StackTrace,
                string.Empty,
                string.Empty,
                });
            }
        }

上述 _executionTime 是我們在此類構造函數中所設置的時間，構造函數如下：

        private readonly string _logFile;
        private readonly int _executionTime;

        public SQLProfiler(string logFile, int executionTime)
        {
            _logFile = logFile;
            _executionTime = executionTime;
        }

而logFile則是我么所要輸出的日志。此時別忘記最重要的一件事，那就是DbConfiguration配置類中進行注冊（或者在配置文件中進行注冊）。如下：

    public class MyDbConfiguration : DbConfiguration
    {
        public MyDbConfiguration()
        {
            this.AddInterceptor(new SQLProfiler(@"D:\log.txt", 1));
        }
    }

接下來我們來進行檢驗結果。

檢驗成果

           using (var ctx = new EntityDbContext())
            {
                SqlParameter[] parameter = { };
                ctx.Database.SqlQuery<Student>("select * from a", parameter).ToList();
                Console.ReadKey();
            }

上述表a實際上是不存在的，我們就是要看看是否能檢測到該異常並獲取其時間。來，瞧一瞧。

【效果一】

【效果二】

結語

當然，如上述當執行查詢時此表不存在肯定是會報錯，但是我們的側重點不在此，這里驗證了此表不存在，同時也驗證了SQL在執行時和執行完之間的耗時，同時我們可以通過構造函數手動設置當耗時大於我們預期的多少才算需要改善SQL。