[.NETCore] ASP.NET Core - 使用 NLog 紀錄日誌資訊 ~ m@rcus 學習筆記

前言
在開發 .NET Framework 時候，一提到紀錄日誌的函式庫大家都會聯想到 NLog 與 Log4Net 兩種 library，兩者都是免費、OpenSource 且各有喜好者，各自提供簡單好使用的方式讓我們輕鬆地可以將需要的資訊生成相關日誌內容，從 .NET Framework 進入到 .Net Core 時代，紀錄 Application Log 勢必也是重要的功能之一，今天就要分享的是在 .NET Core 中如何使用老牌日誌 Library NLog，若有問題歡迎提出一起討論

開始前的小建議
如果對 .NET Core Logging 不熟悉，建議先服用下列兩篇文章效果會更好 ^_^
[.NETCore] ASP.NET Core - Logging 日誌初體驗 (一)
[.NETCore] ASP.NET Core - Logging 日誌初體驗 (二)

1. 安裝 NLog
首先新增一個 .Net Core API 專案對 NLog 進行 Demo，專案取名為 NetCoreNLogLab，專案選擇 API

專案建立完成後，進到 Nuget 介面下載 NLog 及 NLog.Web.AspNetCore

下載完畢之後，到專案 Dependencies 查看是否有 NLog 與 NLog.Web.AspNetCore

或是確認專案檔是否有存在下載 package reference

<PackageReference Include="NLog.Web.AspNetCore" Version="4.8.0" />
<PackageReference Include="NLog" Version="4.5.11" />

2. 新增 NLog.config
在專案根目錄底下新增 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"
      internalLogLevel="Info"
      internalLogFile="c:\temp\internal-nlog.txt">
 
  <!-- enable asp.net core layout renderers -->
  <extensions>
    <add assembly="NLog.Web.AspNetCore"/>
  </extensions>
 
  <!-- the targets to write to -->
  <targets>
    <!-- write logs to file  -->
    <target xsi:type="File" name="allfile" fileName="c:\temp\nlog-all-${shortdate}.log"
            layout="${longdate}|${event-properties:item=EventId_Id}|${uppercase:${level}}|${logger}|${message} ${exception:format=tostring}" />
 
    <!-- another file log, only own logs. Uses some ASP.NET core renderers -->
    <target xsi:type="File" name="ownFile-web" fileName="c:\temp\nlog-own-${shortdate}.log"
            layout="${longdate}|${event-properties:item=EventId_Id}|${uppercase:${level}}|${logger}|${message} ${exception:format=tostring}|url: ${aspnet-request-url}|action: ${aspnet-mvc-action}" />
  </targets>
 
  <!-- rules to map from logger name to target -->
  <rules>
    <!--All logs, including from Microsoft-->
    <logger name="*" minlevel="Trace" writeTo="allfile" />
 
    <!--Skip non-critical Microsoft logs and so log only own logs-->
    <logger name="Microsoft.*" maxlevel="Info" final="true" /> <!-- BlackHole without writeTo -->
    <logger name="*" minlevel="Trace" writeTo="ownFile-web" />
  </rules>
</nlog>

這裡可以看見在設定檔中
- log 檔位寫入位置 fileName 是在 c:\temp 目錄下
- log 資訊開頭 layout 是日期時間當作開頭
詳細的 config file 內容介紹可以參考官網說明 : 傳送門

設定 nlog.config 檔案 copy 方式
設定 config 檔案 copy to output direct 為 copy if newer，已確保執行時能找到 nlog.config 檔案

預設為 Do not copy，在預設情況下執行會遇到 exception Unhandled : System.IO.FileNotFoundException: 'Could not find file 'bin\Debug\netcoreapp2.1\nlog.config'.' 的錯誤訊息發生，因此需要調整 nlog.config 設定資訊，或是手動的方式編輯 csproj 檔案

 < ItemGroup >
    < Content  Update = “ nlog.config ”  CopyToOutputDirectory = “ PreserveNewest ” />
 </ ItemGroup >

3. 更新 program.cs

using NLog.Web;
using Microsoft.Extensions.Logging;
 
public static void Main(string[] args)
{
    // NLog: setup the logger first to catch all errors
    var logger = NLog.Web.NLogBuilder.ConfigureNLog("nlog.config").GetCurrentClassLogger();
    try
    {
        logger.Debug("init main");
        BuildWebHost(args).Build().Run(); 
    }
    catch (Exception ex)
    {
        //NLog: catch setup errors
        logger.Error(ex, "Stopped program because of exception");
        throw;
    }
    finally
    {
        // Ensure to flush and stop internal timers/threads before application-exit (Avoid segmentation fault on Linux)
        NLog.LogManager.Shutdown();
    }
}
 
public static IWebHostBuilder BuildWebHost(string[] args) =>
    WebHost.CreateDefaultBuilder(args)
        .UseStartup<Startup>()
        .ConfigureLogging(logging =>
        {
            logging.ClearProviders();
            logging.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace);
        })
        .UseNLog();  // NLog: setup NLog for Dependency injection

修改 appsettings.json
調整 appsettings.json，否則 appsettings.json 會被 SetMinimumLevel 設定覆蓋掉

 {
     “ Logging ”：{
         “ LogLevel ”：{
             “ Default ”：“ Trace ”，
             “ Microsoft ”：“ Information ”
        }
    }
}

4. 撰寫 Log
在 API 預設的 controller 注入 ILogger覆蓋掉，接著我們在 get function 中輸入 _logger.Loginformation (內建的 logging API )

[Route("api/[controller]")]
[ApiController]
public class ValuesController : ControllerBase
{
    private readonly ILogger<ValuesController> _logger;
 
    public ValuesController(ILogger<ValuesController> logger)
    {
        _logger = logger;
    }
        
    // GET api/values
    [HttpGet]
    public ActionResult<IEnumerable<string>> Get()
    {
        _logger.LogInformation("Value page says hello");
        return new string[] { "value1", "value2" };
    }
}

5. 確認日誌
上面有提到 log 檔位置是在 c:\temp 底下，到該目錄底下發現已經有兩個 log 檔案內容分別如下

nlog-own-2019-03-05.log

2019-03-05 23:56:10.3993||DEBUG|NetCoreNLogLab.Program|init main |url: |action: 
2019-03-05 23:56:16.6200||INFO|NetCoreNLogLab.Controllers.ValuesController|Value page says hello |url: http://localhost/api/values|action: Get

nlog-all-2019-03-05.log

2019-03-05 23:56:10.3993||DEBUG|NetCoreNLogLab.Program|init main 
2019-03-05 23:56:14.3724||INFO|Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager|User profile is available. Using 'C:\Users\marcustung\AppData\Local\ASP.NET\DataProtection-Keys' as key repository and Windows DPAPI to encrypt keys at rest. 
2019-03-05 23:56:15.8142|1|INFO|Microsoft.AspNetCore.Hosting.Internal.WebHost|Request starting HTTP/1.1 GET http://localhost:5012/api/values   
2019-03-05 23:56:15.8142|1|INFO|Microsoft.AspNetCore.Hosting.Internal.WebHost|Request starting HTTP/1.1 DEBUG http://localhost:5012/  0 
2019-03-05 23:56:15.8907|2|INFO|Microsoft.AspNetCore.Hosting.Internal.WebHost|Request finished in 59.6151ms 200  
2019-03-05 23:56:16.4635|1|INFO|Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker|Route matched with {action = "Get", controller = "Values"}. Executing action NetCoreNLogLab.Controllers.ValuesController.Get (NetCoreNLogLab) 
2019-03-05 23:56:16.6200|1|INFO|Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker|Executing action method NetCoreNLogLab.Controllers.ValuesController.Get (NetCoreNLogLab) - Validation state: Valid 
2019-03-05 23:56:16.6200||INFO|NetCoreNLogLab.Controllers.ValuesController|Value page says hello 
2019-03-05 23:56:16.6384|2|INFO|Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker|Executed action method NetCoreNLogLab.Controllers.ValuesController.Get (NetCoreNLogLab), returned result Microsoft.AspNetCore.Mvc.ObjectResult in 9.57ms. 
2019-03-05 23:56:16.6545|1|INFO|Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor|Executing ObjectResult, writing value of type 'System.String[]'. 
2019-03-05 23:56:16.7148|2|INFO|Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker|Executed action NetCoreNLogLab.Controllers.ValuesController.Get (NetCoreNLogLab) in 245.7545ms 
2019-03-05 23:56:16.7148|2|INFO|Microsoft.AspNetCore.Hosting.Internal.WebHost|Request finished in 907.213ms 200 application/json; charset=utf-8 
2019-03-05 23:56:16.8795|1|INFO|Microsoft.AspNetCore.Hosting.Internal.WebHost|Request starting HTTP/1.1 GET http://localhost:5012/favicon.ico   
2019-03-05 23:56:16.8795|2|INFO|Microsoft.AspNetCore.Hosting.Internal.WebHost|Request finished in 1.1443ms 404

紀錄成功 !!!

後記
這篇簡單分享 NLog 在.NET Core 的使用方式，在 NLog 中還是有很多細節根應用可以再繼續學習下去，比如說 NLog 之中的 logger、target 使用方式，根據不同 log level 輸出 title 也不相同，在之後的時間可以在整理出來讓大家更容易了解，謝謝

參考
Getting-started-with-ASP.NET-Core-2

[IIS] 程序無法存取檔案，因為檔案正由另一個程序使用。(發生例外狀況於HRESULT:0x80070020)問題今天要在公司測試 Server 建立測試站台，在完成設定 Application Pool 與站台指定位置後按下啟動，跳出'程序無法存取檔案，因為檔案正由另一個程序使用。(發生例外狀況於HRESULT:0x80070020) 錯誤訊息，訊息內容看似有檔案被 lock 住造成啟動異常，但追根究底之後會發現其異常原因蠻單純的，以下就針對解決此問題的方式做說明，若有問題歡迎提出一起討論或是給予指導。解決方案根… Read More
[IIS] IIS 站台服務異常中止 - HttpEvent 問題今天同事反應測試主機 IIS Server 無法使用，進到 QA 主機後發現所有的 IIS 服務都已停止，第一直覺就是到事件檢視器查看是否有異常的 Log 資訊，發現事件檢視器紀錄其中來源 HttpEvent 嫌疑重大，以下就針對解決此問題的方式做說明，若有問題歡迎提出一起討論或是給予指導。解決方案由於公司測試機對外預設都是以 80 port 為主，無故發生異常是蠻很奇怪，過去… Read More
[UnitTest] 如何測試目標方法中 Guid 型別的代碼 ?情境如果要產生一個亂數時很常會想到 Guid 方法解決，在 C# 使用 Guid 的方式相當簡單僅要透過 Guid.NewGuid 靜態方法產生一組 Guid 使用，在目前公司很常看到使用 Guid 作為識別碼，今天在重構舊代碼時忽然想到如果遇到 Guid 該如何進行加上單元測試，以下就目前想到的解法進行測試與說明，如果各位高手們有更好的方法歡迎高抬貴手一起討論研究。解決方案寫個簡單的 Sa… Read More
[.NETCore] 如何取得 appsettings.json 組態設定問題在開發時有時會將資訊紀錄在 Web.Config 設定檔中的開發經驗，在 .NET Framework 要取得 web.config 自訂組態設定時可以透過 ConfigurationManager.AppSettings ，相信大家都有了解且不陌生；但今天場景換到 ASP.NET Core 時，在一開始建立好新專案後只有 appsettings.json 設定檔，那麼該如何… Read More
[VisualStudio] .NET 分析測試代碼覆蓋率 AxoCover前言最近在替既有專案補上單元測試，除了在 SonarQube 可以看到測試代碼覆蓋率之外，這幾天同事推薦一套可以在 Visual Studio 執行的程式碼覆蓋率分析工具 AxoCover，可運行在 .NET 環境且開源免費，簡單玩了一下覺得十分不錯推薦給大家，今天就來分享 AxoCover 在 Visual Studio 2017 的安裝及基本操作說明。安裝 AxoCover Step 1 :… Read More

m@rcus 學習筆記

只有累積，沒有奇蹟

2019年3月5日星期二