[ASP.NET Core] 使用 NLog 紀錄 IP 及 TraceId,但值都是空的

啟動一個新專案時,都會翻翻找找之前的專案,把想要的設定拿(偷)過來用,而 NLog.config 裡面用到了兩個 Layout Renderers:

  1. aspnet-request-ip
  2. aspnet-TraceIdentifier

開發時看到Log的這兩個資訊都是空白的,想想本機跑的關係吧,就隨它去了,直到丟上Server看到Log怎麼還是空白的,驚覺不對勁趕緊來確認問題,記錄一下排查的過程。

專案環境

  1. Asp.Net Core 3.1
  2. NLog.Web.AspNetCore 4.9.2
<!--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">
    <extensions>
        <add assembly="NLog.Web.AspNetCore" />
    </extensions>
    <variable name="log-root" value="Log" />
    <variable name="log-daily" value="${log-root}/${date:format=yyyy}/${date:format=yyyy-MM}/${shortdate}" />
    <targets>
        <target encoding="utf-8" xsi:type="File" name="debug-all"
                fileName="${log-daily}/${shortdate}.log"
                layout="[${time}][${aspnet-request-ip}][${logger}][${level}][${aspnet-TraceIdentifier}] - ${message}" />
    </targets>
    <rules>
        <logger name="*" minlevel="Debug" writeTo="debug-all" />
    </rules>
</nlog>

NLog.config 的 throwConfigExceptions 已經指定 true,專案跑的起來也能寫Log,先排除是 config 錯誤,

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
      autoReload="true"
      throwConfigExceptions="true">

再為 NLog.config 加上設定,把內部的 Log 都寫出來

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
      autoReload="true"
      throwConfigExceptions="true"
      internalLogLevel="Debug"
      internalLogFile="NLog.Internal.txt"
      internalLogToConsole="true">

接著在 NLog.Internal.txt 看到…

2020-07-02 11:12:50.2132 Debug Missing serviceProvider, so no HttpContext
2020-07-02 11:12:50.2132 Debug Missing serviceProvider, so no HttpContext
2020-07-02 11:12:50.2145 Debug Missing serviceProvider, so no HttpContext

把 Log 丟去 Google 一下找了這兩篇,大略就是說不要同時使用 AddNlog 和 UseNLog,在 ASP.NET Core2 之後請使用 UseNLog

HttpContextAccessor is null in AspNetLayoutRendererBase

UseNLog vs AddNLog and asp.net core layout renderers

To make things more clear:
AddNLog is for ASP.NET Core 1, build for Configure(IApplicationBuilder app, …)
UseNLog is the new pattern for ASP.NET Core 2 and 3, build for IWebHostBuilder

That depends on the ASP.NET Core version.
It’s not recommend to mix both. AddNLog is now also obsolete (as ASP.NET Core 1 is EOL)

再回頭看了一下程式碼,的確同時使用了 AddNLog 和 UseNLog

 public void ConfigureServices(IServiceCollection services)
{
    services.AddLogging(config =>
    {
        config.AddNLog();
    });
}
public class Program
{
    public static IHostBuilder CreateHostBuilder(string[] args)
    {
        return Host.CreateDefaultBuilder(args)
            .ConfigureWebHostDefaults(webBuilder =>
            {
                webBuilder.UseStartup<Startup>()
                    .UseNLog();
            });
    }
}

把 AddNLog 移除後再執行一下專案,確認 Log 的兩個資訊都有值了,搞了半天 Bug 都還是自己搞出來的(笑)

[11:32:11.6731][::1][Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker][Info][|99df034d-4bc0f44a6f9e001a.] - ...
[11:32:11.6798][::1][Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor][Info][|99df034d-4bc0f44a6f9e001a.] - ...
[11:32:11.6813][::1][Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker][Info][|99df034d-4bc0f44a6f9e001a.] - ...
[11:32:11.6813][::1][Microsoft.AspNetCore.Routing.EndpointMiddleware][Info][|99df034d-4bc0f44a6f9e001a.] - ...
[11:32:11.6823][::1][Microsoft.AspNetCore.Hosting.Diagnostics][Info][|99df034d-4bc0f44a6f9e001a.] - ...

在 ASP.NET,NLog提供了很多的 Layout Renderers 可以使用,適當的使用可以減少許多排查log的時間

NLog Layout Renderers