2025年1月1日 星期三

在 .NET9 Web API 專案使用NLog來量測程式碼效能

在 .NET9 Web API 專案使用NLog來量測程式碼效能

在上一篇文章 在 .NET9 Web API 專案使用NLog教學與紀錄Trace Id，有說明如何從無到有的在一個 ASP.NET Core 專案內，安裝與設定 NLog 這個套件，並且可以相系統運作資訊寫入到 Log 內。

在這篇文章中，將延續上篇文章中用到的專案，探討如何使用 NLog 來量測程式碼的效能，來記錄下每個方法的執行時間，並且將這些資訊寫入到 Log 內。

建立量測效能的類別

在這個專案中，我們將會建立一個類別 PerformanceMonitor，這個類別將會用來量測每個方法的執行時間，這個類別將會透過 NLog 來記錄下每個方法的執行時間。

在這個類別內，我們將會使用 Stopwatch 這個類別來量測每個方法的執行時間，這個類別是在 System.Diagnostics 命名空間內。

using System.Diagnostics;

namespace csNlogTraceId;

public class PerformanceLogger : IDisposable
{
    private readonly Stopwatch _stopwatch;
    private readonly string _taskName;
    private readonly ILogger _logger;

    public PerformanceLogger(ILogger _logger, string taskName)
    {
        _taskName = taskName;
       this._logger = _logger;
        _stopwatch = Stopwatch.StartNew();
        _logger.LogInformation("{TaskName} 開始執行", _taskName);
    }

    public void Dispose()
    {
        _stopwatch.Stop();
        _logger.LogInformation("{TaskName} 結束執行, Execution time: {ElapsedMilliseconds} ms",
            _taskName, _stopwatch.ElapsedMilliseconds);
    }
}

在這個類別內，我們建立了一個建構式 PerformanceLogger，這個建構式接受兩個參數，一個是 ILogger 這個介面，另一個是 taskName 這個參數，這個參數將會用來記錄下這個方法的名稱。

這類別實作了 [IDisposable] 介面，這個介面內有一個方法 Dispose，這個方法將會在這個類別被釋放時，執行這個方法，這個方法將會停止 Stopwatch 這個類別的執行，並且記錄下這個方法的執行時間。

建立長時間運作的控制器 LongTaskController

在這個專案中，我們將會建立一個控制器 LongTaskController，這個控制器將會有一個方法 Get，這個方法將會模擬一個長時間運作的方法，這個方法將會在執行時，透過 PerformanceLogger 這個類別來量測這個方法的執行時間。

using Microsoft.AspNetCore.Mvc;
using NLog;

namespace csNlogTraceId.Controllers;

[ApiController]
[Route("[controller]")]
public class LongTaskController : ControllerBase
{
    private readonly ILogger<LongTaskController> _logger;

    public LongTaskController(ILogger<LongTaskController> logger)
    {
        _logger = logger;
    }

    [HttpGet]
    public async Task Get()
    {
        _logger.LogInformation("進入到控制內做些一秒的工作");
        await Task.Delay(1000);
        using (var perfLogger = new PerformanceLogger(_logger, "量測程式碼範例"))
        {
            await Task.Delay(5000);
        }
    }
}

啟動並執行這個專案

  • 在 Visual Studio 2022 IDE 中，按下 F5 鍵，或者是在功能表中選擇 [除錯] -> [開始偵錯]，來執行這個程式

當專案啟動之後，並沒有看到任何瀏覽器出現

開啟瀏覽器輸入 https://localhost:7014/LongTask 這個網址，這時，將會看到瀏覽器顯示程式碼區塊的執行效能的訊息

此時，在 Console 中，將會看到底下內容，顯示的呼叫這個 API 時候，所寫入的日誌內容 




By 於 沒有留言:
標籤： , ,

在.NET9 Web API 專案使用NLog教學與紀錄Trace Id

在.NET9 Web API 專案使用NLog教學與紀錄Trace Id

在這篇文章中，我們將建立起一個.NET9 的ASP.NET Core Web API 項目，並且說明如何安裝與設定和使用NLog，由於這是一個Web API 項目，所以，將會透過Trace Id 來記錄下每次HTTP 請求的時候，與此有關的Log 有哪些，透過NLog 來記錄Trace Id 與Exception 的紀錄

建立測試專案

請依照底下的操作，建立起這篇文章需要用到的練習項目

  • 打開Visual Studio 2022 IDE 應用程式
  • 從[Visual Studio 2022] 對話窗中，點選右下方的[建立新的項目] 按鈕
  • 在[建立新項目] 對話窗右半部
    • 切換[所有語言(L)] 下拉選單控制項為[C#]
    • 切換[所有項目類型(T)] 下拉選單控制項為[Web API]
  • 在中間的項目模板清單中，找到並且點擊[ASP.NET Core Web API] 項目模板選項

    此專案模板可用於ASP.NET Core 控制器或最小API 建立RESTful Web API，並可選擇性支援OpenAPI 和驗證

  • 點擊右下角的[下一步] 按鈕
  • 在[設定新的項目] 對話窗
  • 找到[項目名稱] 字段，輸入csNlogTraceId作為項目名稱
  • 在剛剛輸入的[項目名稱] 欄位下方，確認沒有勾選[將解決方案與項目至於相同目錄中] 這個檢查盒控制項
  • 點擊右下角的[下一步] 按鈕
  • 現在將會看到[其他資訊] 對話窗
  • 在[架構] 欄位中，請選擇最新的開發框架，這裡選擇的[架構] 是 :.NET 9.0 (標準字詞支援)
  • 在[驗證類型] 選擇無
  • 在這個練習中，需要去勾選[不要使用最上層陳述式(T)] 這個檢查盒控制項

    這裡的這個操作，可以由讀者自行決定是否要勾選這個檢查盒控制項

  • 請點擊右下角的[建立] 按鈕

稍微等候一下，這個項目將會建立完成

安裝要用的NuGet 開發套件

因為開發此專案時會使用這些NuGet 套件，請依照底下說明，將需要用到的NuGet 套件安裝。

安裝NLog.Web.AspNetCore 套件

請依照底下說明操作步驟，將這個套件安裝到專案內

  • 鼠標右擊[方案總管] 視窗內的[專案節點] 下方的[依賴] 節點
  • 從彈出功能表清單中，點選[管理NuGet 套件] 這個功能選項清單
  • 此時，將會看到[NuGet: csNlogTraceId] 視窗
  • 切換此視窗的標籤頁次到名稱為[瀏覽] 這個標籤頁次
  • 在左上方找到一個搜尋文字輸入盒，在此輸入NLog.Web.AspNetCore
  • 在視窗右方，將會看到該套件詳細說明的內容，其中，右上方有的[安裝] 按鈕
  • 點擊這個[安裝] 按鈕，將這個套件安裝到專案內

建立一個中介軟件類別TraceIdMiddleware

在這個專案中，我們將建立一個中介軟件類別TraceIdMiddleware，這個中介軟件類別將會用來記錄下每次HTTP 請求的Trace Id，這個值將由[HttpContext.TraceIdentifier] 來取得，這個Trace Id 將會被NLog 用來記錄下每次HTTP 請求的Log 訊息，而這裡將會透過了NLog.MappedDiagnosticsLogicalContext 這個類別來設定TraceId 的值。

在[nlog.config] 內，若想要顯示TraceId，可以透過${mdlc:TraceId}這個格式來取得TraceId 的值

namespace csNlogTraceId;

public class TraceIdMiddleware
{
    private readonly RequestDelegate _next;
    private readonly ILogger<TraceIdMiddleware> logger;

    public TraceIdMiddleware(RequestDelegate next,
        ILogger<TraceIdMiddleware> logger)
    {
        _next = next;
        this.logger = logger;
    }

    public async Task InvokeAsync(HttpContext context)
    {
        try
        {
            var traceId = context.TraceIdentifier;
            NLog.MappedDiagnosticsLogicalContext.Set("TraceId", traceId);
            await _next(context);
        }
        catch (Exception ex)
        {
            // 记录异常
            logger.LogError(ex, "發生不可預期的錯誤");
            // 将异常重新抛出
            //throw;
        }
    }
}

在[InvokeAsync] 方法內，將會使用try...catch 敘述將其捕捉起來，並且透過NLog 來記錄下這個Exception 的訊息，這樣，當發生Exception 的時候，將會記錄下這個Exception 的訊息，並且該Exception 的訊息將包含TraceId 的值

修改Program.cs 類別內容

  • 找到並且打開[Program.cs] 這個檔案
  • 使用底下程式碼替換掉這個檔案的內容
using NLog;
using NLog.Web;

namespace csNlogTraceId
{
    public class Program
    {
        public static void Main(string[] args)
        {
            var logger = NLogBuilder.ConfigureNLog("nlog.config").GetCurrentClassLogger();
            try
            {
                var builder = WebApplication.CreateBuilder(args);

                builder.Logging.ClearProviders();
                builder.Logging.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace);
                builder.Host.UseNLog();

                // Add services to the container.

                builder.Services.AddControllers();
                // Learn more about configuring OpenAPI at https://aka.ms/aspnet/openapi
                builder.Services.AddOpenApi();

                var app = builder.Build();

                app.UseMiddleware<TraceIdMiddleware>();
                
                // Configure the HTTP request pipeline.
                if (app.Environment.IsDevelopment())
                {
                    app.MapOpenApi();
                }

                app.UseHttpsRedirection();

                app.UseAuthorization();


                app.MapControllers();

                app.Run();
            }
            catch (Exception ex)
            {
                logger.Error(ex, "Stopped program because of an exception");
                throw;
            }
            finally
            {
                LogManager.Shutdown();
            }
        }
    }
}

這裡先使用[NLogBuilder.ConfigureNLog("nlog.config")] 設定NLog 的設定文件，接著，透過[GetCurrentClassLogger()] 來取得Logger 的實例，這樣，就可以透過這個Logger 來記錄下Log 訊息

接著，透過[builder.Logging.ClearProviders()] 來清除原本的Log 訊息提供者，接著，透過[builder.Logging.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace)] 來設定最低的Log 等級為Trace，這樣，就可以記錄所有的Log 訊息

接著，透過[builder.Host.UseNLog()] 設定使用NLog 來記錄Log 訊息

接著，透過[app.UseMiddleware()] 來設定使用TraceIdMiddleware 這個中間軟件類別，這樣，每次HTTP 請求的時候，將會記錄下TraceId 的值

修改nlog.config 內容

  • 滑鼠右擊專案節點
  • 從彈出的功能表清單中，點選[新增項目] 功能選項
  • 在[新增項目] 對話窗中，點選對話窗左方的[已安裝] > [C#] > [ASP.NET Core] > [資料]
  • 在[新增項目] 對話窗右方，找到[XML 檔] 這個項目，並且點擊它
  • 在[名稱] 欄位中，輸入nlog.config
  • 點擊[新增] 按鈕
  • 使用底下的代碼替換掉這個檔案的內容
<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
	  xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
	  autoReload="true"
      throwConfigExceptions="true"
      internalLogLevel="Info"
      internalLogFile="internal-nlog.log">
	<!-- 日志级别：Trace < Debug < Info < Warn < Error < Fatal -->
	<targets>
		<!-- 文件输出目标 -->
		<target xsi:type="AsyncWrapper" name="File_async"
				overflowAction="Discard"
				queueLimit="500000"
				batchSize="500">
			<target name="file" xsi:type="File" fileName="logs/logfile-${shortdate}.log"
				layout="${longdate}|${mdlc:TraceId}|${level:uppercase=true}|${logger}|${message}|${exception:format=toString,StackTrace}" />
		</target>
		<!-- 控制台输出目标 -->
		<target xsi:type="AsyncWrapper" name="Console_async"
		overflowAction="Discard"
		queueLimit="500000"
		batchSize="500">
			<target name="console" xsi:type="Console"
				layout="${longdate}|${mdlc:TraceId}|${level:uppercase=true}|${logger}|${message}|${exception:format=toString,StackTrace}" />
		</target>
	</targets>

	<rules>
		<!-- Suppress output from Microsoft framework when non-critical -->
		<logger name="System.*" finalMinLevel="Warn" />
		<logger name="Microsoft.*" finalMinLevel="Warn" />
		<!-- Keep output from Microsoft.Hosting.Lifetime to console for fast startup detection -->
		<logger name="Microsoft.Hosting.Lifetime*" finalMinLevel="Info" writeTo="console_async" />
		<!-- 最低级别为 Info，输出到文件和控制台 -->
		<logger name="*" minlevel="Info" writeTo="file_async,console_async" />
	</rules>
</nlog>

這裡設定了兩個Target，一個是File_async，另一個是Console_async，這樣，就可以將Log 訊息同時輸出到檔案與Console 上。

對於非同步的日誌寫入，這裡設定了[AsyncWrapper] 這個Target，這樣，就可以將Log 訊息寫入到檔案與Console 上，這樣，就可以提高Log 訊息的寫入效能，這裡用到的參數有[overflowAction] 這個參數，這個參數可以設定當Log 訊息寫入的速度超過了設定的速度時，該如何處理，這裡設定為[Discard]，這樣，當Log當訊息寫入的速度超過了設定的速度時，就會捨棄掉這些Log 訊息，這樣，就可以避免Log 訊息寫入的速度過快，而導致系統的效能下降。對於[queueLimit] 這個參數，這個參數可以設定Log 訊息的隊列上限，這樣，就可以避免Log 訊息寫入的速度過快，而導致系統的效能下降，這裡設定為500000，這樣，就可以讓Log訊息的隊列上限為500000，這樣，就可以避免Log 訊息寫入的速度過快，而導致系統的效能下降。對於[batchSize] 這個參數，這個參數可以設定Log 訊息的批次寫入數量，這樣，就可以提高Log 訊息的寫入效能，這裡設定為500，這樣，就可以讓Log 訊息的批次寫入數量為500，這樣，就可以提高Log 訊息的寫入效能。

對於[layout] 這個參數，這個參數可以設定Log 訊息的格式，這裡設定為${longdate}|${mdlc:TraceId}|${level:uppercase=true}|${logger}|${message}|${exception:format=toString,StackTrace}，這樣，就可以讓Log 訊息的格式為[日期時間]|TraceId|Log等級|Logger名稱|Log訊息|Exception訊息，這樣，就可以讓Log 訊息的格式更清晰易讀。

在[rules] 區段內，這裡設定了兩個Logger，一個是System.*，另一個是Microsoft.*，這樣，就可以讓這兩個Logger 的Log 訊息等級最低為Warn，這樣，就可以避免這兩個Logger 的Log訊息過多，而導致系統的效能下降。對於Microsoft.Hosting.Lifetime*這個Logger，這裡設定了Log 訊息的等級最低為Info，這樣，就可以讓這個Logger 的Log 訊息等級最低為Info，這樣，就可以讓這個Logger 的Log 訊息在Console 上顯示，這樣，就可以讓開發者在開發時，可以看到這個Logger 的Log 訊息，這樣，就可以讓開發者更容易了解這個Logger 的Log 訊息。對於*這個Logger，這裡設定了Log 訊息的等級最低為Info，這樣，就可以讓這個Logger 的Log 訊息等級最低為Info，這樣，就可以讓這個Logger 的Log 訊息在Console 上顯示，這樣，就可以讓開發者在開發時，可以看到這個Logger 的Log 訊息，這樣，就可以讓開發者更容易了解這個Logger 的Log 訊息。

建立會拋出例外異常的控制器

  • 在[Controllers] 資料夾內，建立一個新的C# 類別檔案，並命名為ExceptionController.cs
  • 使用底下的代碼替換掉這個檔案的內容
using Microsoft.AspNetCore.Mvc;
using NLog;

namespace csNlogTraceId.Controllers;

[ApiController]
[Route("[controller]")]
public class ThrowExceptionController : ControllerBase
{
    private readonly ILogger<ThrowExceptionController> _logger;

    public ThrowExceptionController(ILogger<ThrowExceptionController> logger)
    {
        _logger = logger;
    }

    [HttpGet]
    public IEnumerable<WeatherForecast> Get()
    {
        _logger.LogInformation("開始執行測試例外異常 API");

        throw new Exception("這是一個測試例外異常");
    }
}

啟動並執行這個項目

  • 在Visual Studio 2022 IDE 中，按下F5鍵，或是在功能表中選擇[調試] -> [開始調試]，來執行這個程序

當項目啟動之後，並沒有看到任何瀏覽器出現

這裡是項目一啟動之後，Console顯示的Log 內容

開啟瀏覽器輸入https://localhost:7014/WeatherForecast這個網址，這時，將會看到瀏覽器顯示天氣預報資訊的消息

此時，在Console 中，將會看到底下內容，顯示的呼叫這個API 時候，所寫入的日誌內容

開啟瀏覽器輸入https://localhost:7014/ThrowException這個網址，這時，這個API 將會拋出例外異常到Log 內

此時，在Console 中，將會看到底下內容，顯示的呼叫這個API 時候，所寫入的例外異常日誌內容

 




By 於 沒有留言:
標籤： , ,
訂閱： 文章 (Atom)