2020年10月13日 星期二

在 ASP.NET Core Blazor 專案內,觀察送出的 SQL 敘述

在 ASP.NET Core Blazor 專案內,觀察送出的 SQL 敘述

根據 上一篇 EF Core 討論文章 使用 LoggerFactory 觀察 EF Core 送出的 SQL Statement ,了解到如何透過 [LoggerFactory] 這個工廠方法來建立可以產生日誌 Log 紀錄資訊的有用資料,藉以觀察 EF Core 產生了甚麼 SQL 敘述到 Server Server 內,而不用透過 SQL Server Profiler 來觀察。

在這篇文章中,來了解如何在 ASP.NET Core 的專案內,這裡將會使用 Blazor Server-Side 類型的專案作為講解與練習的範本,如何觀察 EF Core 產生了哪些 SQL 敘述到 SQL Server 內。

關於更多這方面的應用,可以參考 .NET Core 與 ASP.NET Core 中的記錄 這份文件內容。

請按照底下的步驟來進行操作

建立練習專案

  • 打開 Visual Studio 2019

  • 點選 [建立新的專案] 按鈕

  • 在 [建立新專案] 對話窗內,選擇 [Blazor 應用程式] 專案樣板

  • 在 [設定新的專案] 對話窗內,於 [專案名稱] 欄位內輸入 efBlazorLogging

  • 在 [建立新的 Blazor 應用程式] 對話窗內,選擇 [Blazor 伺服器應用程式] 這個選項

    在該對話窗右半部的其他選項,可以不用變更

  • 點選 [建立] 按鈕,以便開始建立這個專案

加入 Entity Framework Core 要使用到的 NuGet 套件

  • 滑鼠右擊專案內的 [相依性] 節點
  • 選擇 [管理 NuGet 套件]
  • 點選 [瀏覽] 標籤分頁頁次
  • 在 [搜尋] 文字輸入盒內,輸入 [Microsoft.EntityFrameworkCore.SqlServer]
  • 點選 [安裝] 按鈕以便安裝這個套件
  • 在 [搜尋] 文字輸入盒內,輸入 [Microsoft.EntityFrameworkCore.Tools]
  • 點選 [安裝] 按鈕以便安裝這個套件

使用反向工程來產生 Entity Framework 要用到的 Entity 模型相關類別

  • 切換到 [套件管理器主控台] 視窗

    若沒有看到 [套件管理器主控台] 視窗,點選功能表 [工具] > [NuGet 套件管理員] > [套件管理器主控台]

  • 在 [套件管理器主控台] 輸入底下內容

    因為都在同一個專案內,所以,這裡可以省略 StartupProject & Project 這兩個參數,因此,底下的指令會更為精簡

Scaffold-DbContext "Data Source=(localdb)\MSSQLLocalDB;Initial Catalog=School" Microsoft.EntityFrameworkCore.SqlServer -OutputDir Models -f

修改 Blazor 頁面可以透過 Entity Framework Core 讀取資料庫內的紀錄

  • 在專案根目錄下,打開 [Startup.cs] 這個檔案
  • 找到 [ConfigureServices] 方法,在該方法內加入 services.AddDbContext<SchoolContext>(); 敘述
public void ConfigureServices(IServiceCollection services)
{
    services.AddRazorPages();
    services.AddServerSideBlazor();
    services.AddSingleton<WeatherForecastService>();
    services.AddDbContext<SchoolContext>();
}
  • 找到 [Pages] 資料夾,打開這個 [Index.razor] 檔案,完成底下的程式碼
@page "/"
@using efBlazorLogging.Models
@using Microsoft.EntityFrameworkCore
@using Microsoft.Extensions.Logging
@inject ILogger<Index> logger
@inject SchoolContext context

<h1>Hello, Entity Framework Logging!</h1>

<div>
    <button class="btn btn-primary" @onclick="ReadAsync">開始讀取資料庫</button>
</div>

@if (people != null)
{
    <div>
        @foreach (var item in people)
        {
            <div class="text-success">@item.FirstName</div>
        }
    </div>
}

@code{
    List<Person> people = new List<Person>();

    async Task ReadAsync()
    {
        logger.LogInformation("開始讀取資料庫", null);
        people = await context.Person.ToListAsync();

        // SchoolContext 一定要由相依注入取得,才會自動擁有 Log 能力
        //using (var context = new SchoolContext())
        //{
        //    people = await context.Person.ToListAsync();
        //}
    }
}

這個頁面會呼叫 context.Person.ToListAsync(); 非同步方法,取得所有 [Person] 資料表內的紀錄,並且儲存在 people 變數內;一旦這個集合類型的變數有資料,透過 Blazor 的資料綁定,便會將所有的人員記錄顯示在網頁上。

這裡使用了幾個技巧,首先宣告 @inject ILogger<Index> logger 要注入 ILogger 物件,因此,在這個頁面便可以將自動邏輯要顯示的 Log 內容,透過 logger 執行個體來輸出到日誌記錄內;例如,這裡使用了 logger.LogInformation("開始讀取資料庫", null); 這樣的敘述,將會在 Log 指定輸出的目的地顯示 開始讀取資料庫 文字

第二,這裡不能夠自己使用 new 運算子來產生 DbContext 物件,因為這樣將無法正常的取得 Entity Framework 內的輸出日誌內容;因此,這裡一樣需要宣告 @inject SchoolContext context 這樣的敘述,要求注入 SchoolContext 物件。

這裡可以這樣使用 ,這是因為前面有在 [Startup] 類別內,執行了 services.AddDbContext<SchoolContext>(); 敘述

執行這個專案並且觀察執行結果

  • 請執行這個專案

  • 當網頁顯示的職後,請點選 [開始讀取資料庫] 按鈕

  • 稍等一下,就會看到如下的網頁

  • 底下是 Console 視窗中的輸出內容

info: Microsoft.Hosting.Lifetime[0]
      Now listening on: https://localhost:5001
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:5000
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: D:\Vulcan\GitHub\CSharp2020\efBlazorLogging\efBlazorLogging
info: efBlazorLogging.Pages.Index[0]
      開始讀取資料庫

現在發現到問題了,那就是自己指定 Log 輸出有成功顯示於 Console 內,而 Entity Framework Core 的相關產生 SQL 指定的內容,卻沒有顯示在 Console 內,因此,要來做些修正。

指定 Entity Framework Core 要顯示那些等級的 Log

  • 請打開 [appsettings.Development.json] 檔案
  • 在這個檔案內的 LogLevel 內,加入一個屬性 : "Microsoft.EntityFrameworkCore": "Information" ;完成後的全部內容,如底下清單所示
{
  "DetailedErrors": true,
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft": "Warning",
      "Microsoft.EntityFrameworkCore": "Information",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  }
}
  • 重新再執行一次這個專案,並且點選讀取資料庫的按鈕
  • 此時,從 Console 視窗內將會看到底下內容
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: https://localhost:5001
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:5000
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: D:\Vulcan\GitHub\CSharp2020\efBlazorLogging\efBlazorLogging
info: efBlazorLogging.Pages.Index[0]
      開始讀取資料庫
info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 3.1.8 initialized 'SchoolContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (56ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [p].[PersonID], [p].[EnrollmentDate], [p].[FirstName], [p].[HireDate], [p].[LastName]
      FROM [Person] AS [p]

現在終於可以看到 Entity Framework Core 所產生的 SQL 指令;這裡的做法可以參考 設定記錄 文件說明,關於各種 LogLevel 可以使用的內容,可以參考 LogLevel 列舉

這裡根據文件上的內容,列出各種日誌等級的說明

欄位

LogLevel列舉值說明
Trace0包含最詳細訊息的記錄。 這些訊息可能包含敏感性應用程式資料。 這些訊息預設會停用,且永遠不應在生產環境中啟用。
Debug1開發期間用於互動式調查的記錄。 這些記錄主要應包含適用於偵錯的資訊,且不具備任何長期值。
Information2追蹤應用程式一般流程的記錄。 這些記錄應具備長期值。
Warning3醒目提示應用程式流程中異常或未預期事件的記錄,這些異常或未預期事件不會造成應用程式執行停止。
Error4在目前執行流程因失敗而停止時進行醒目提示的記錄。 這些記錄應指出目前活動中的失敗,而非整個應用程式的失敗。
Critical5描述無法復原的應用程式或系統損毀,或需要立即注意重大失敗的記錄。
None6不會用來寫入記錄訊息。 指定記錄類別不應寫入任何訊息。

現在來嘗試將 EF Core LogLevel 切換為 Trace

  • 請打開 [appsettings.Development.json] 檔案
  • 在將屬性 "Microsoft.EntityFrameworkCore" 的值修改成為 "Trace" ;完成後的全部內容,如底下清單所示
{
  "DetailedErrors": true,
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft": "Warning",
      "Microsoft.EntityFrameworkCore": "Trace",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  }
}
  • 重新再執行一次這個專案,並且點選讀取資料庫的按鈕
  • 此時,從 Console 視窗內將會看到底下內容
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: https://localhost:5001
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:5000
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: D:\Vulcan\GitHub\CSharp2020\efBlazorLogging\efBlazorLogging
info: efBlazorLogging.Pages.Index[0]
      開始讀取資料庫
dbug: Microsoft.EntityFrameworkCore.Infrastructure[10409]
      An additional 'IServiceProvider' was created for internal use by Entity Framework. An existing service provider was not used due to the following configuration changes: configuration changed for 'Core:ConfigureWarnings', configuration added for 'SqlServer:UseRowNumberForPaging'.
dbug: Microsoft.EntityFrameworkCore.Model[10601]
      The index {'CourseId'} was not created on entity type 'CourseInstructor' as the properties are already covered by the index {'CourseId', 'PersonId'}.
info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 3.1.8 initialized 'SchoolContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
dbug: Microsoft.EntityFrameworkCore.Query[10107]
      queryContext => new QueryingEnumerable<Person>(
          (RelationalQueryContext)queryContext,
          RelationalCommandCache,
          null,
          null,
          Func<QueryContext, DbDataReader, ResultContext, int[], ResultCoordinator, Person>,
          efBlazorLogging.Models.SchoolContext,
          null
      )
dbug: Microsoft.EntityFrameworkCore.Database.Command[20103]
      Creating DbCommand for 'ExecuteReader'.
dbug: Microsoft.EntityFrameworkCore.Database.Command[20104]
      Created DbCommand for 'ExecuteReader' (30ms).
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20000]
      Opening connection to database 'School' on server '(localdb)\MSSQLLocalDB'.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20001]
      Opened connection to database 'School' on server '(localdb)\MSSQLLocalDB'.
dbug: Microsoft.EntityFrameworkCore.Database.Command[20100]
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [p].[PersonID], [p].[EnrollmentDate], [p].[FirstName], [p].[HireDate], [p].[LastName]
      FROM [Person] AS [p]
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (51ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [p].[PersonID], [p].[EnrollmentDate], [p].[FirstName], [p].[HireDate], [p].[LastName]
      FROM [Person] AS [p]
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.ChangeTracking[10806]
      Context 'SchoolContext' started tracking 'Person' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.
dbug: Microsoft.EntityFrameworkCore.Database.Command[20300]
      A data reader was disposed.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20002]
      Closing connection to database 'School' on server '(localdb)\MSSQLLocalDB'.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20003] 

      Closed connection to database 'School' on server '(localdb)\MSSQLLocalDB'. 




2020年10月12日 星期一

使用 LoggerFactory 觀察 EF Core 送出的 SQL Statement

使用 LoggerFactory 觀察 EF Core 送出的 SQL Statement

根據 上一篇 EF Core 討論文章 使用 DbContextOptionsBuilder 來指定連線字串與觀察 EF Core 產生的 SQL 指令 ,透過 SQL Server Profiler 來觀察使用 EF Core 的程式,究竟產生了甚麼 SQL 指令到 SQL Server 上,現在,使用另外一種方式來觀察究竟執行了甚麼 SQL指令,在這裡需要使用 LoggerFactory 這個類別來做到這件事情。根據官方文件上提到的,這個類別的目的是 : 根據指定的提供者,產生 ILogger 類別的執行個體。

根據這份文件內容 .NET Core 與 ASP.NET Core 中的記錄 可以得知, [ILogger] 是用於提供支援記錄 API。

請按照底下的步驟來進行操作

建立練習專案

  • 打開 Visual Studio 2019
  • 點選 [建立新的專案] 按鈕
  • 在 [建立新專案] 對話窗內,選擇 [主控台應用程式 (.NET Core)] 專案樣板
  • 在 [設定新的專案] 對話窗內,於 [專案名稱] 欄位內輸入 efLoggerFactory
  • 點選 [建立] 按鈕,以便開始建立這個專案

加入 Entity Framework Core 要使用到的 NuGet 套件

  • 滑鼠右擊專案內的 [相依性] 節點
  • 選擇 [管理 NuGet 套件]
  • 點選 [瀏覽] 標籤分頁頁次
  • 在 [搜尋] 文字輸入盒內,輸入 [Microsoft.EntityFrameworkCore.SqlServer]
  • 點選 [安裝] 按鈕以便安裝這個套件
  • 在 [搜尋] 文字輸入盒內,輸入 [Microsoft.EntityFrameworkCore.Tools]
  • 點選 [安裝] 按鈕以便安裝這個套件

使用反向工程來產生 Entity Framework 要用到的 Entity 模型相關類別

  • 切換到 [套件管理器主控台] 視窗

    若沒有看到 [套件管理器主控台] 視窗,點選功能表 [工具] > [NuGet 套件管理員] > [套件管理器主控台]

  • 在 [套件管理器主控台] 輸入底下內容

    因為都在同一個專案內,所以,這裡可以省略 StartupProject & Project 這兩個參數,因此,底下的指令會更為精簡

Scaffold-DbContext "Data Source=(localdb)\MSSQLLocalDB;Initial Catalog=School" Microsoft.EntityFrameworkCore.SqlServer -OutputDir Models -f

請打開這個 [Program.cs] 檔案,完成底下的程式碼

using efLoggerFactory.Models;
using Microsoft.EntityFrameworkCore;
using Microsoft.Extensions.Logging;
using System;
using System.Linq;

namespace efLoggerFactory
{
    class Program
    {
        public static readonly ILoggerFactory MyLoggerFactory
            = LoggerFactory.Create(builder =>
            {
                builder.AddConsole();
            });
        static void Main(string[] args)
        {
            string connectionString = @"Data Source=(localdb)\MSSQLLocalDB;Initial Catalog=School";
            DbContextOptions<SchoolContext> options = new DbContextOptionsBuilder<SchoolContext>()
                .UseLoggerFactory(MyLoggerFactory)
                .UseSqlServer(connectionString)
                .Options;
            using (var context = new SchoolContext(options))
            {
                Console.WriteLine($"取得 StudentGrade 第一筆紀錄");
                var aStudentGrade = context.StudentGrade.FirstOrDefault();
                Console.WriteLine($"更新成績為 4.99");
                aStudentGrade.Grade = 4.99m;
                context.SaveChanges();
            }
        }
    }
}

從上面的程式碼中,宣告了一個靜態的 ILoggerFactory 型別變數 , ILoggerFactory , 透過 [LoggerFactory.Create] 這個工廠方法,產生出一個物件,在呼叫這個工廠方法的時候,也宣告了使用螢幕 Console 作為輸出日誌的目的地,這裡可以參考 ConsoleLoggerExtensions.AddConsole 方法 文件。

接著,如同上一篇文章 使用 DbContextOptionsBuilder 來指定連線字串與觀察 EF Core 產生的 SQL 指令 做法,先建立一個 [DbContextOptions] 物件,不過,當該物件建立之後,會呼叫 [UseLoggerFactory] 這個方法,並且把 MyLoggerFactory 物件傳送進去,如此,便可以透過這個 [ILogger] 執行個體來觀察 EF Core 產生的 SQL 敘述。

執行結果如下

取得 StudentGrade 第一筆紀錄
info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 3.1.7 initialized 'SchoolContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (29ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT TOP(1) [s].[EnrollmentID], [s].[CourseID], [s].[Grade], [s].[StudentID]
      FROM [StudentGrade] AS [s]
更新成績為 4.99
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (37ms) [Parameters=[@p1='?' (DbType = Int32), @p0='?' (DbType = Decimal)], CommandType='Text', CommandTimeout='30']
      SET NOCOUNT ON;
      UPDATE [StudentGrade] SET [Grade] = @p0
      WHERE [EnrollmentID] = @p1;
      SELECT @@ROWCOUNT;

觀察上面的輸出內容,可以但看到當 SchoolContext 進行初始化的時候,會使用 Microsoft.EntityFrameworkCore.SqlServer 這個提供者,接著便會執行底下的 SQL 指令,查詢出 StudentGrade 資料表內的紀錄

Executed DbCommand (29ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
SELECT TOP(1) [s].[EnrollmentID], [s].[CourseID], [s].[Grade], [s].[StudentID]
FROM [StudentGrade] AS [s]

最後執行底下的 SQL Command ,更新該筆紀錄

 Executed DbCommand (37ms) [Parameters=[@p1='?' (DbType = Int32), @p0='?' (DbType = Decimal)], CommandType='Text', CommandTimeout='30']
 SET NOCOUNT ON;
 UPDATE [StudentGrade] SET [Grade] = @p0
 WHERE [EnrollmentID] = @p1; 

SELECT @@ROW 




2020年10月9日 星期五

使用 DbContextOptionsBuilder 來指定連線字串與觀察 EF Core 產生的 SQL 指令

使用 DbContextOptionsBuilder 來指定連線字串與觀察 EF Core 產生的 SQL 指令

接續 上一篇 EF Core 討論文章 DbContext 在多執行緒環境下的運作情況 ,有些時候,當要使用 DbContext 來建立一個可以存取資料庫的 EF Core 的物件,想要能夠自行指定連線字串,可以在該繼承 DbContext 的類別建構函式內,傳入要使用的連線字串,並且於 OnConfiguring 方法內,使用該傳入的連線字串做為要連線到資料庫的依據;不過,這裡使用另外一個方式,那就是使用 DbContextOptionsBuilder 型別,產生一個這個物件,以便指定要使用的連線字串。

請按照底下的步驟來進行操作

建立練習專案

  • 打開 Visual Studio 2019
  • 點選 [建立新的專案] 按鈕
  • 在 [建立新專案] 對話窗內,選擇 [主控台應用程式 (.NET Core)] 專案樣板
  • 在 [設定新的專案] 對話窗內,於 [專案名稱] 欄位內輸入 efDbContextOptionsBuilder
  • 點選 [建立] 按鈕,以便開始建立這個專案

加入 Entity Framework Core 要使用到的 NuGet 套件

  • 滑鼠右擊專案內的 [相依性] 節點
  • 選擇 [管理 NuGet 套件]
  • 點選 [瀏覽] 標籤分頁頁次
  • 在 [搜尋] 文字輸入盒內,輸入 [Microsoft.EntityFrameworkCore.SqlServer]
  • 點選 [安裝] 按鈕以便安裝這個套件
  • 在 [搜尋] 文字輸入盒內,輸入 [Microsoft.EntityFrameworkCore.Tools]
  • 點選 [安裝] 按鈕以便安裝這個套件

使用反向工程來產生 Entity Framework 要用到的 Entity 模型相關類別

  • 切換到 [套件管理器主控台] 視窗

    若沒有看到 [套件管理器主控台] 視窗,點選功能表 [工具] > [NuGet 套件管理員] > [套件管理器主控台]

  • 在 [套件管理器主控台] 輸入底下內容

    因為都在同一個專案內,所以,這裡可以省略 StartupProject & Project 這兩個參數,因此,底下的指令會更為精簡

Scaffold-DbContext "Data Source=(localdb)\MSSQLLocalDB;Initial Catalog=School" Microsoft.EntityFrameworkCore.SqlServer -OutputDir Models -f

現在 Entity Model 相關資料已經建立完成

請觀察 [SchoolContext.cs] 檔案,這裡的 SchoolContext 類別繼承了 DbContext 類別,不過,這裡有兩個建構式,一個是預設建構函式,也就是沒有任何參數的建構式,另外一個建構式可以接收 [DbContextOptions] 這個型別的物件;另外,在 [OnConfiguring] 覆寫方法內,將會檢查傳入的 [DbContextOptionsBuilder] 物件的 [IsConfigured] 屬性是否為 真,用來確認是否已經指定了連線字串,若沒有指定的話,將會在這裡使用預設的本機 localDB 資料庫之連線字串。

    public partial class SchoolContext : DbContext
    {
        public SchoolContext()
        {
        }
 
        public SchoolContext(DbContextOptions<SchoolContext> options)
            : base(options)
        {
        }
 
        protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        {
            if (!optionsBuilder.IsConfigured)
            {
#warning To protect potentially sensitive information in your connection string, you should move it out of source code. See http://go.microsoft.com/fwlink/?LinkId=723263 for guidance on storing connection strings.
                optionsBuilder.UseSqlServer("Data Source=(localdb)\\MSSQLLocalDB;Initial Catalog=School");
            }
        }
 
        protected override void OnModelCreating(ModelBuilder modelBuilder)
        {
             . . .
            OnModelCreatingPartial(modelBuilder);
        }
 
        partial void OnModelCreatingPartial(ModelBuilder modelBuilder);
    }

因此,透過上面的解說,將會進行相關的程式開發與設計

請打開這個 [Program.cs] 檔案,完成底下的程式碼

static void Main(string[] args)
{
    string connectionString = @"Data Source=(localdb)\MSSQLLocalDB;Initial Catalog=School";
    DbContextOptions<SchoolContext> options = new DbContextOptionsBuilder<SchoolContext>()
        .UseSqlServer(connectionString)
        .Options;
    using (var context = new SchoolContext(options))
    {
        Console.WriteLine($"取得 StudentGrade 第一筆紀錄");
        var aStudentGrade = context.StudentGrade.FirstOrDefault();
        Console.WriteLine($"{aStudentGrade.StudentId} 學生的 {aStudentGrade.CourseId} 課程的成績為 {aStudentGrade.Grade}");
    }
}

從上面的程式碼中,可以看到首先建立了一個 connectionString 字串物件,該字串即是準備要用到的連線字串,緊接著建立一個 [DbContextOptions] 泛型型別物件,在該物件建立之後,便呼叫 [UseSqlServer] 方法,只是此次要 EF Core 使用指定的連線字串,連線到 SQL Server 服務上,最後,透過 [Options] 屬性,取得此次設定的相關內容。

如此,便可以建立 [SchoolContext] DbContext 物件,不過,需要在該建構函式內傳入剛剛產生的 [DbContextOptions] 物件,如此,一切準備工作都就緒了,便可以透過 [context] 變數來取得後端 SQL Server 內資料表的紀錄。

執行結果如下

取得 StudentGrade 第一筆紀錄
2 學生的 2021 課程的成績為 4.00

最後,要來觀察究竟 EF Core 產生了甚麼 SQL 指定到後端 SQL Server 內,此時,便可以透過 SSMS (SQL Server Management Studio) 這個工具來觀察,請打開此連結 SSMS ,下載與安裝這個工具。

安裝好之後,請找到 SQL Server Profilee 18 這個應用程式,並且打開與執行。

點選功能表 [檔案] > [新增追蹤] 選項

當 [連線至伺服器] 對話窗出現之後,請在 [伺服器名稱] 欄位內,輸入 (localdb)\. 內容

SQL Profiler

點選 [連線] 按鈕,連線到 SQL Server Express LocalDB 上

當出現 [連線屬性] 對話窗,點選 [執行按鈕]

SQL Profiler 連線屬性

現在可以重新執行剛剛建立的 [efDbContextOptionsBuilder] 專案;一旦執行完成之後,便可以看到底下的內容

SQL Profiler 連線屬性

從上面的 SQL Server Profiler 畫面中,可以看到此次將送出底下的 SQL指令到 SQL Server 內,而這個 SQL 指令是因為程式中執行了 context.StudentGrade.FirstOrDefault(); 敘述, EF Core 根據這個 C# 敘述所產生出來的 SQL 指令。

SELECT TOP(1) [s].[EnrollmentID], [s].[CourseID], [s].[Grade], [s].[StudentID] 

FROM [StudentGrade] AS [s] 




2020年10月8日 星期四

DbContext 在多執行緒環境下的運作情況

DbContext 在多執行緒環境下的運作情況

在上篇文章中 Console 專案與 EF Core 讀取已經存在的資料庫 ,可以知道如何在 Console 類型的專案內,加入 EF Core 套件,便可以透過 EF Core 框架所提供的功能,存取後端資料庫內的資料。在這篇文章中,將來探討論外一個問題,那就是需要在多執行緒的多工環境下,若使用同一個 DbContext 會發生甚麼問題。

請按照底下的步驟來進行操作

建立練習專案

  • 打開 Visual Studio 2019
  • 點選 [建立新的專案] 按鈕
  • 在 [建立新專案] 對話窗內,選擇 [主控台應用程式 (.NET Core)] 專案樣板
  • 在 [設定新的專案] 對話窗內,於 [專案名稱] 欄位內輸入 efMultiThread
  • 點選 [建立] 按鈕,以便開始建立這個專案

加入 Entity Framework Core 要使用到的 NuGet 套件

  • 滑鼠右擊專案內的 [相依性] 節點
  • 選擇 [管理 NuGet 套件]
  • 點選 [瀏覽] 標籤分頁頁次
  • 在 [搜尋] 文字輸入盒內,輸入 [Microsoft.EntityFrameworkCore.SqlServer]
  • 點選 [安裝] 按鈕以便安裝這個套件
  • 在 [搜尋] 文字輸入盒內,輸入 [Microsoft.EntityFrameworkCore.Tools]
  • 點選 [安裝] 按鈕以便安裝這個套件

使用反向工程來產生 Entity Framework 要用到的 Entity 模型相關類別

  • 切換到 [套件管理器主控台] 視窗

    若沒有看到 [套件管理器主控台] 視窗,點選功能表 [工具] > [NuGet 套件管理員] > [套件管理器主控台]

  • 在 [套件管理器主控台] 輸入底下內容

    因為都在同一個專案內,所以,這裡可以省略 StartupProject & Project 這兩個參數,因此,底下的指令會更為精簡

Scaffold-DbContext "Data Source=(localdb)\MSSQLLocalDB;Initial Catalog=School" Microsoft.EntityFrameworkCore.SqlServer -OutputDir Models -f

現在 Entity Model 相關資料已經建立完成

請打開這個 [Program.cs] 檔案,完成底下的程式碼

class Program
{
    static async Task Main(string[] args)
    {
        SchoolContext context = new SchoolContext();
 
        var task1 = Task.Run(async () =>
        {
            for (int i = 0; i < 100; i++)
            {
               var people= await context.Person
                .AsNoTracking()
                .OrderBy(x => x.LastName).ToListAsync();
                foreach (var item in people)
                {
                    Console.Write($"{item.LastName} ");
                }
            }
        });
        var task2 = Task.Run(async () =>
        {
            for (int i = 0; i < 100; i++)
            {
                var courses = await context.Course
                 .AsNoTracking()
                 .OrderBy(x => x.Title).ToListAsync();
                foreach (var item in courses)
                {
                    Console.Write($"{item.Title} ");
                }
            }
        });
        await Task.WhenAll(task1, task2);
    }
}

從上面的程式碼中,可以看到首先建立了一個 SchoolContext 型別的 context 物件,這個物件就代表了遠端的資料庫,而接下來將會透過 Task.Run 方法 建立兩個非同步工作 物件,代表未來與承諾會完成這個非同步工作內指定的需求,在這兩個非同步工作內,分別會執行 100 次的迴圈,每次迴圈分別會對 Person & Course 資料表,讀取遠端資料庫內的所有紀錄回本機電腦內;基本上,看樣子的設計,似乎沒有甚麼衝突可以發生,因為,雖然有兩個非同步工作,這兩個非同步工作都是做查詢而已,而且是分別在不同資料表內做查詢,可是,當執行這個程式碼之後,便會發生底下的錯誤訊息:

System.InvalidOperationException: 'An attempt was made to use the context while it is being configured. A DbContext instance cannot be used inside OnConfiguring since it is still being configured at this point. This can happen if a second operation is started on this context before a previous operation completed. Any instance members are not guaranteed to be thread safe.'

System.InvalidOperationException

通常,第一次看到這樣的錯誤訊息的時候,絕大多數的人都是很迷惘了,究竟發生了甚麼問題,可是仔細看這段訊息,會看到這樣的內容 Any instance members are not guaranteed to be thread safe. 這裡充分說明了 DbContext 的類別所產生單一物件,不能夠使用於多執行緒環境下,在微軟官方文件中,也有提到這樣的內容

Entity Framework Core does not support multiple parallel operations being run on the same DbContext instance. This includes both parallel execution of async queries and any explicit concurrent use from multiple threads. Therefore, always await async calls immediately, or use separate DbContext instances for operations that execute in parallel.

When EF Core detects an attempt to use a DbContext instance concurrently, you'll see an InvalidOperationException with a message like this:

A second operation started on this context before a previous operation completed. This is usually caused by different threads using the same instance of DbContext, however instance members are not guaranteed to be thread safe.

When concurrent access goes undetected, it can result in undefined behavior, application crashes and data corruption.

所以,這樣的用法就算僅作查詢或分別針對不同資料表做查詢,一樣會產生例外異常。

若想要修正這樣的問題,可以參考底下的作法,就可以避免掉執行緒不安全的問題。

static async Task Main(string[] args)
{
 
    var task1 = Task.Run(async () =>
    {
        using (SchoolContext context = new SchoolContext())
        {
            for (int i = 0; i < 100; i++)
            {
                var people = await context.Person
                 .AsNoTracking()
                 .OrderBy(x => x.LastName).ToListAsync();
                foreach (var item in people)
                {
                    Console.Write($"{item.LastName} ");
                }
            }
        }
    });
    var task2 = Task.Run(async () =>
    {
        using (SchoolContext context = new SchoolContext())
        {
            for (int i = 0; i < 100; i++)
            {
                var courses = await context.Course
                 .AsNoTracking()
                 .OrderBy(x => x.Title).ToListAsync();
                foreach (var item in courses)
                {
                    Console.Write($"{item.Title} ");
                }
            }
        }
    });
    await Task.WhenAll(task1, task2); 

}