ログの出力とファイルに吐き出す方法

ASP.NET Coreを利用したプロジェクトのログ出力と出力されたログをファイルに吐き出す方法のメモです。Visual Studio 2017で新規に作成したプロジェクト（ASP.NET Core Webアプリケーション）をベースにしています。

• Visual Studio 2017
• ASP.NET Core 2.0
• NLog.Web.AspNetCore 4.4.1

デバッグ時に出力ウィンドウへログを吐き出したいだけなら、以下のようなコードで出力されます。

using Microsoft.Extensions.Logging;

namespace SapmleApp.Controllers
{
    public class ExampleController : Controller
    {
        private readonly ILogger _logger;

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

        public IActionResult Index()
        {
            _logger.LogTrace("Test log level Trace.");
            _logger.LogDebug("Test log level Debug.");
            _logger.LogInformation("Test log level Information.");
            _logger.LogWarning("Test log level Warning.");
            _logger.LogError("Test log level Error.");
            _logger.LogCritical("Home log level Critical.");
            return View();
        }
    }
}

上記で出力しているログをファイルへ吐き出す場合、以下の手順を行います。

ファイルへ出力する場合、NLogというライブラリを利用するのが一般的のようです。

NLogにはプラットフォーム別にいくつか種類があるようですが、今回は「NLog.Web.AspNetCore」を使います。違いはログの出力にリクエストの情報を付加することができる点のようです。

インストールはNuGetパッケージマネージャーで行います。（ツール ＞ NuGetパッケージマネージャー ＞ ソリューションのNuGetパッケージの管理）

管理画面から「NLog.Web.AspNetCore」を検索して、導入したいプロジェクトを選択してインストールを行います。

続いて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="Warn"
      internalLogFile="c:\temp\internal-nlog.txt">

  <!-- Load the ASP.NET Core plugin -->
  <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}|${logger}|${uppercase:${level}}|${message} ${exception}" />

    <!-- 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}|${logger}|${uppercase:${level}}|  ${message} ${exception}|url: ${aspnet-request-url}|action: ${aspnet-mvc-action}" />

    <!-- write to the void aka just remove -->
    <target xsi:type="Null" name="blackhole" />
  </targets>

  <!-- rules to map from logger name to target -->
  <rules>
    <!--All logs, including from Microsoft-->
    <logger name="*" minlevel="Trace" writeTo="allfile" />

    <!--Skip Microsoft logs and so log only own logs-->
    <logger name="Microsoft.*" minlevel="Trace" writeTo="blackhole" final="true" />
    <logger name="*" minlevel="Trace" writeTo="ownFile-web" />
  </rules>
</nlog>

上記の設定はNLogのサイトにあったものをコピペしたものですが、大きく分けて3種類のログファイルをc直下のtempフォルダに出力しています。

• internal-nlog.txt
• nlog-all-${shortdate}.log
• nlog-own-${shortdate}.log

「internal-nlog.txt」は設定やログ関連の内部処理でエラーが出た場合に出力されます。

「nlog-all-${shortdate}.log」はすべてのログ（フレームワークやライブラリのログ、自分で用意したログ）が出力され、その中で標準ライブラリのログ（Microsoft.*）を除外したものを「nlog-own-${shortdate}.log」に出力するという設定のようです。

ファイル名の${shortdate}は「yyyy-MM-dd」となるので、日単位でログファイルが作成されることになります。

ビルド時にこのnlog.configファイルが出力ディレクトリへコピーされるように、nlog.configファイルのプロパティ設定ダイアログを開いて、設定項目「出力ディレクトリにコピー」を「常にコピーする」に変更します。

デフォルトで用意されているstartup.csを以下のように変更（追記）します。

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

namespace SapmleApp
{
    public class Startup
    {
        public Startup(IHostingEnvironment env)
        {
            env.ConfigureNLog("nlog.config");
        }

        public void ConfigureServices(IServiceCollection services)
        {
            services.AddMvc();
            services.AddSingleton<IHttpContextAccessor, HttpContextAccessor>();
        }

        public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory)
        {
            loggerFactory.AddNLog();
            app.AddNLogWeb();
        }
    }
}

実際に出力されるログは以下のようになります。

nlog-all-${shortdate}.log

2017-10-06 13:39:31.8984|0|SampleApp.Controllers.ExsampleController|INFO|Test log level Information. 
2017-10-06 13:39:31.9252|0|SampleApp.Controllers.ExsampleController|WARN|Test log level Warning. 
2017-10-06 13:39:31.9302|0|SampleApp.Controllers.ExsampleController|ERROR|Test log level Error. 
2017-10-06 13:39:31.9362|0|SampleApp.Controllers.ExsampleController|FATAL|Test log level Critical. 

nlog-own-${shortdate}.log

2017-10-06 13:39:31.8984|0|SampleApp.Controllers.ExsampleController|INFO|  Test log level Information. |url: http://localhost/|action: Index
2017-10-06 13:39:31.9252|0|SampleApp.Controllers.ExsampleController|WARN|  Test log level Warning. |url: http://localhost/|action: Index
2017-10-06 13:39:31.9302|0|SampleApp.Controllers.ExsampleController|ERROR|  Test log level Error. |url: http://localhost/|action: Index
2017-10-06 13:39:31.9362|0|SampleApp.Controllers.ExsampleController|FATAL|  Test log level Critical. |url: http://localhost/|action: Index

ログは出力されていましたが、よくよく確認すると「Trace」と「Debug」のログがファイルに出力されていませんでした。

最初はnlog.configの設定が間違っているのかと思いましたが、minlevelに「Info」以上のログレベルを設定するとちゃんとレベル以上のログのみ出力されました。

原因はよく分かりませんが、この現象はASP.NET Core 2.0を使っていた場合に発生するようです。

「Trace」や「Debug」ログをファイルへ出力したい場合は、「program.cs」を以下のように修正します。

program.cs

namespace SampleApp
{
    public class Program
    {
        public static void Main(string[] args)
        {
            BuildWebHost(args).Run();
        }

        public static IWebHost BuildWebHost(string[] args) =>
            WebHost.CreateDefaultBuilder(args)
                .ConfigureLogging((builder) =>
                {
                    builder.SetMinimumLevel(LogLevel.Trace);
                })
                .UseStartup<Startup>()
                .Build();
    }
}

上記の「builder.SetMinimumLevel(LogLevel.Trace);」を追加した上で、ファイルに出力されるログのレベルの調整をnlog.configで行います。

nlog.configのminlevelに設定できるレベルは以下の通りです。

• Trace
• Debug
• Info（Informationは×）
• Warn（Warningは×）
• Error
• Fatal

上記の手順を行った上で実行すると、internal-nlog.txtに以下のような警告ログが出力されます。

Warn Missing IHttpContextAccessor. Has it been registered before loading NLog Configuration? Consider reloading NLog Configuration after having registered the IHttpContextAccessor.

このログが出ないようにしたかったのですが、どうすれば出なくなるのか分かりませんでした。

もしかしたら、Visual Sutido 2017やASP.NET Core 2.0を使っていたら出力されてしまうログなのかもしれません。

• Logging in ASP.NET Core | Microsoft Docs
• NLog · GitHub
• Getting started with ASP.NET Core (csproj vs2017) · NLog/NLog.Web Wiki · GitHub
• Missing Trace/Debug logs (.NET core 2) · Issue #167 · NLog/NLog.Web · GitHub
• Getting-started-with-ASP.NET-Core vs2017 · Issue #157 · NLog/NLog.Web · GitHub
• NLog 設定項目 詳細: C#　プログラミング　再入門