.NET Core, ASP.NET CoreでNLogを使ってログを出力する

はじめに

前の記事では、.NET Core のコンソールアプリケーションで NLog を使ってログを出力する方法をご紹介しましたが、今回は ASP.NET Core での方法をご紹介したいと思います。

気をつけなければいけないのが、コンソールアプリケーションでは NLog.Extensions.Logging パッケージをインストールするのですが、ASP.NET Core では NLog.Web.AspNetCore をインストールする必要があることです。

なぜこんなことになっているかは不明ですが、NLog の公式ページで書いてあるのでなにか事情があるのでしょう。

さて、今回も環境は Mac (macOS High Sierra 10.13.3) で .NET Core SDK 2.1.4、Visual Studio Code になります。

とは言っても、Windowsでもパスを読み替えれば使えると思います。もともと Windows のツールですので。

ASP.NET Core アプリケーションの作成

まずは、ASP.NET Core の MVC アプリケーションを下記コマンドで作成します。

$ dotnet new mvc -o WebLog

パッケージのインストール

NLog 関連のパッケージを NuGet でインストールします。.NET Core 2.0 では NLog 4.5.x 以上が必要とのことなので、正式版ではありませんが最新版をインストールします。対象は、NLog.Web.AspNetCore と NLog になります。

$ dotnet add package NLog.Web.AspNetCore --version 4.5.0-rc3
$ dotnet add package NLog --version 4.5.0-rc07

設定ファイル

NLog の設定ファイルをプロジェクトのルートに 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="/tmp/log/internal-nlog.txt">


  <!-- the targets to write to -->
  <targets>
    <!-- write logs to file  -->
    <target xsi:type="File" name="allfile" fileName="/tmp/log/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="/tmp/log/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>

Microsoft 関連のログをチュートリアルで出力しているようにしている意味は分かりませんが、とりあえずここではその設定に従っています。不要なら削除してもかまわないと思います。

この設定では、Trace 以上のログ（要は全て）の場合にログを出力するようになっています。なお、${shortdate} とすることでファイル名に日付を入れることができます。

nlog.config ファイルがビルド時にビルド先にコピーされるように、.csproj に以下の内容を追加します。

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

また、appsettings.json と appsettings.Development.json の内容を以下のようにします。２つのファイルの内容が同じになるよう注意します。

{
  "Logging": {
    "LogLevel": {
      "Default": "Trace",
      "Microsoft": "Information"
    }
  }
}

ソースコードの修正

いきなりですが、Program.cs を以下のように書き換えます（抜粋）。

using Microsoft.Extensions.Logging;
using NLog;
using NLog.Web;

//(中略)

    public static void Main(string[] args)
    {
        var logger = NLog.LogManager.LoadConfiguration("nlog.config").GetCurrentClassLogger();
        try {
            logger.Debug("init main");
            BuildWebHost(args).Run();
        } catch (Exception ex) {
            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 IWebHost BuildWebHost(string[] args) =>
        WebHost.CreateDefaultBuilder(args)
            .UseStartup<Startup>()
            .ConfigureLogging(logging =>
            {
                logging.ClearProviders();
                logging.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace);  //これがないと正常動作しない模様
            })
            .UseNLog()
            .Build();

そして、Controller クラスである HomeController.cs を以下のように書き換えます（抜粋）。

using Microsoft.Extensions.Logging;

//(中略)

public class HomeController : Controller
{
    private readonly ILogger<HomeController> _logger;

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

    public IActionResult Index()
    {
        _logger.LogInformation("Index page says hello");
        return View();
    }

//(略)

ビルド＆実行

準備が整ったので、ビルドおよび実行をしてみます。

$ dotnet build
$ dotnet run

実行後、コンソールに表示されるアドレスにアクセスするとログが出力されるので内容を確認します。

$ cat nlog-own-2018-03-20.log
2018-03-20 20:34:55.0920||DEBUG|WebLog.Program|init main |url: |action:
2018-03-20 20:35:08.7392||INFO|WebLog.Controllers.HomeController|Index page says hello |url: |action:

期待通りの動作ですね。

nlog.config のログレベルを変更すれば、ログにフィルターがかかり出力するログレベルを変更することができます。

おわりに

ASP.NET Core で NLog を使ってログを出力するのは、結構苦労するかと思いましたが意外と簡単にできました。

この辺が人気の理由かもしれませんね。

オプションも豊富にあるみたいですし、試してみるのもいいと思います。

参考サイト

• Getting started with ASP.NET Core 2 · NLog/NLog.Web Wiki