NLog を使用してログを出力する

ページ作成日 : 2021年4月29日木曜日

環境

Visual Studio

Visual Studio 2019

ASP.NET Core

5.0 (MVC, Razor ページ)

はじめに

NLog は設定に応じてログをファイルやメール、データベースに出力することができるようになっています。

NLog は ASP.NET Core の標準のログシステムに組み込むことができるようになっているため、デフォルトのロガーを使用したまま設定に応じたログの出力が可能となっています。

ログレベルについて

Microsoft のログ、NLog いずれにおいても以下の６段階に分かれており、出力レベルもほぼ一致しています。

レベル	Microsoft	NLog
0	Trace	Trace
1	Debug	Debug
2	Information	Info
3	Warning	Warn
4	Error	Error
5	Critical	Fatal
(6)	(None)	(Off)

レベルが高いほどログの重要度が高くなり、ログの出力制約に関わらず書き出される可能性が高くなります。

ログ出力手順

NLog のパッケージの導入

ASP.NET Core プロジェクトを作成したらパッケージを追加します。

プロジェクトの「依存関係」を右クリックして「NuGet パッケージの管理」を選択します。

「参照」タブをクリックして検索欄に「NLog」と入力すると NLog 関連のパッケージが表示されます。

NLog を選択し、最新の安定版を選択している状態でインストールボタンをクリックします。

OK をクリックします。

NLog.Web.AspNetCore もインストールします。

パッケージがプロジェクトに追加されました。

nlog.config の追加

NLog のログの出力定義である nlog.config をプロジェクトに追加します。中身は XML 形式なので 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"
      internalLogLevel="Info"
      throwConfigExceptions="true"
      internalLogFile="${basedir}/internal-nlog-AspNetCore.txt">

  <!-- ログの出力レイアウトを変数 layoutDefine で定義 -->
  <variable name="layoutDefine"
            value="${longdate} [${event-properties:item=EventId_Id:whenEmpty=0}][${level:padding=-5}] ${message} ${exception:format=tostring} (${callsite:includeNamespace=false:fileName=true:includeSourcePath=false})" />

  <!-- 書き込むターゲット -->
  <targets>
    <!-- Visual Studio の出力 (デバッグ) に書き込みます -->
    <target xsi:type="Trace" name="TraceOutput" rawWrite="true" layout="${layoutDefine}" />

    <!-- 基本的な詳細を含むすべてのログメッセージのファイルターゲット -->
    <target xsi:type="File" name="FileOutput" fileName="${aspnet-appbasepath}/Log-${shortdate}.log" layout="${layoutDefine}" />

    <!-- Docker / Visual Studio の起動検出を改善するためにライフタイムメッセージをホストするためのコンソールターゲット  -->
    <target xsi:type="Console" name="LifetimeConsole" layout="${level:truncate=4}\: ${logger}[0]${newline}      ${message}${exception:format=tostring}" />
  </targets>

  <!-- ロガー名からターゲットにマップするルール -->
  <rules>
    <!-- Microsoft からのものを含むすべてのログ -->
    <logger name="*" writeTo="TraceOutput" />

    <!-- 起動の検出を高速化するために、ホスティングライフタイムメッセージをコンソールターゲットに出力します。Microsoft.Hosting.Lifetime はここより下の定義には出力しません -->
    <logger name="Microsoft.Hosting.Lifetime" minlevel="Info" writeTo="LifetimeConsole" final="true" />

    <!-- 重要でない Microsoft ログをスキップして、自分のログのみをログに記録する。システムが出す Warning 以上のログ以外はここより下の定義には出力されません -->
    <logger name="Microsoft.*" maxlevel="Info" final="true" />
    <logger name="System.Net.Http.*" maxlevel="Info" final="true" />

    <!-- 上記で除外したもの以外をファイルに出力 -->
    <logger name="*" writeTo="FileOutput" />
  </rules>
</nlog>

nlog.config のプロパティで「ビルドアクション：コンテンツ」「出力ディレクトリにコピー：新しい場合はコピーする」に設定されていることを確認してください。

appsetting.json の編集

デフォルトでは nlog.config をどのように設定しても Information 以上のレベルしか出力されません。これはログ出力が appsetting.json にも依存しているためです。

appsetting.json を開いて Logging.LogLevel.Default の値を Trace に変更してください。 NLog を使用するのであればレベルの調整は NLog 側で行うので appsetting.json の設定を Trace にすることにより実質全レベルを出力できます。

{
  "Logging": {
    "LogLevel": {
      "Default": "Trace",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  },
  "AllowedHosts": "*"
}

また、開発時は appsettings.Development.json の設定の方が読み込まれるのでこちらも同様に変更します。

{
  "DetailedErrors": true,
  "Logging": {
    "LogLevel": {
      "Default": "Trace",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  }
}

NLog のプログラムの準備

NLog の仕組みでログを出力できるようにプログラムを追加します。

Program.cs ファイルを開き、以下のように修正します。

using NLog.Web;  // 追加

// 省略

public class Program
{
  public static void Main(string[] args)
  {
    var logger = NLogBuilder.ConfigureNLog("nlog.config").GetCurrentClassLogger();
    try
    {
      CreateHostBuilder(args).Build().Run();
    }
    catch (Exception exception)
    {
      // NLog：セットアップエラーをキャッチ
      logger.Error(exception, "例外のためにプログラムを停止しました。");
      throw;
    }
    finally
    {
      // アプリケーションを終了する前に、内部タイマー/スレッドをフラッシュして停止するようにしてください
      // (Linux でのセグメンテーション違反を回避してください）
      NLog.LogManager.Shutdown();
    }
  }

  public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
      .ConfigureWebHostDefaults(webBuilder =>
      {
        webBuilder.UseStartup<Startup>();
      })
      .ConfigureLogging(logging =>
      {
        logging.ClearProviders();                 // NLog 以外で設定された Provider の無効化.
        logging.SetMinimumLevel(LogLevel.Trace);  // 最小ログレベルの設定
      })
      .UseNLog();  // NLog：依存性注入のための NLog のセットアップ
}

ログの出力

MVC プロジェクトの場合 HomeComtroller, Razor ページの場合は IndexModel のコンストラクタに ILogger<IndexModel> logger が渡されていると思います。また、プライベートフィールドの _logger にも設定されているので、これを使用してログを出力することができます。

以下は Razor ページによる出力例ですが、MVC でも同じコードで出力可能です。

// 省略

public class IndexModel : PageModel
{
  private readonly ILogger<IndexModel> _logger;
  
  public IndexModel(ILogger<IndexModel> logger)
  {
    _logger = logger;
    
    _logger.LogTrace("Trace で出力します。");
    _logger.LogDebug("Debug で出力します。");
    _logger.LogInformation("Information で出力します。");
    _logger.LogWarning("Warning で出力します。");
    _logger.LogError("Error で出力します。");
    _logger.LogCritical("Critical で出力します。");
    
    _logger.LogInformation(1, "EventID ありで出力します。");
  }
  
  public void OnGet()
  {
    _logger.LogInformation("ページを表示するタイミングでログを出力します。");
  }
}

デバッグ実行すると、プロジェクトのフォルダの中にログファイルが出来ていると思います。

ファイルの中身を見るとログを確認できます。

サンプルの nlog.config の解説

順番に説明していますが、あまり重要でない部分は説明は省いています。

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
      autoReload="true"
      internalLogLevel="Info"
      throwConfigExceptions="true"
      internalLogFile="${basedir}/internal-nlog-AspNetCore.txt">

NLog 自体のログの出力設定などのパラメータがあります。

internalLogFile はそのログの出力先になります。ログの出力自体にエラーがあった場合などの参考になります。${basedir} はプログラムの実行フォルダを指します。

internalLogLevel は NLog のログの出力レベルです。Off にすると一切出力されません。

<!-- ログの出力レイアウトを変数 layoutDefine で定義 -->
<variable name="layoutDefine"
          value="${longdate} [${event-properties:item=EventId_Id:whenEmpty=0}][${level:padding=-5}] ${message} ${exception:format=tostring} (${callsite:includeNamespace=false:fileName=true:includeSourcePath=false})" />

ログの内容をどのようなレイアウトで出力するかを変数に設定しています。後のターゲットに直接入力することもできますが、同じレイアウトを複数指定する場合は変数で１個にまとめた方が管理が楽です。

レイアウトにどのようなパラメータを指定できるかは 公式サイト を参照したほうがよいでしょう。

参考にここで指定しているパラメータは以下のような形式で出力されます。

パラメータ	出力内容
longdate	「2021-03-17 11:46:36.5034」のような年月日時分秒
event-properties	プログラムで指定したログ出力のイベントID などを表示します
level	「Trace」や「Error」などのレベル
message	プログラムのログ出力で指定したメッセージ
exception	プログラムのログ出力で Exception を渡した場合の内容
callsite	ログの出力場所やファイル名など

出力例

2021-03-17 11:46:37.3537 [0][Info ] ページを表示するタイミングでログを出力します。  (IndexModel.OnGet(Index.cshtml.cs:26))

<!-- 書き込むターゲット -->
<targets>
  <!-- Visual Studio の出力 (デバッグ) に書き込みます -->
  <target xsi:type="Trace" name="TraceOutput" rawWrite="true" layout="${layoutDefine}" />

  <!-- 基本的な詳細を含むすべてのログメッセージのファイルターゲット -->
  <target xsi:type="File" name="FileOutput" fileName="${aspnet-appbasepath}/Log-${shortdate}.log" layout="${layoutDefine}" />

  <!-- Docker / Visual Studio の起動検出を改善するためにライフタイムメッセージをホストするためのコンソールターゲット  -->
  <target xsi:type="Console" name="LifetimeConsole" layout="${level:truncate=4}\: ${logger}[0]${newline}      ${message}${exception:format=tostring}" />
</targets>

出力するターゲットを指定します。複数指定可能です。

一つ目は xsi:type="Trace" を指定しており、ログが Visual Studio の出力ウィンドウに出力されます。主にデバッグ実行で確認する際に使用できます。

二つ目は xsi:type="File" を指定しており、指定したパスのファイルにログを出力します。パスに ${shortdate} を指定するとログを出力した時点の年月日のファイルにログを書き込むことができます。また ${aspnet-appbasepath} を指定すると Web プロジェクトのルートフォルダが指定されます。ただ、運用する際にはプログラムの入れ替えやセキュリティを考慮して Web ディレクトリの外にログファイルを出力するようにした方がよいでしょう。

三つ目は xsi:type="Console" を指定しており、コンソールアプリにおいてのコンソールに表示させることができます。 ASP.NET Core 自体はコンソールアプリではありませんが、Docker や Azure などの環境において状態をコンソールに表示させることができるので、その際に使用することもできます。こちらは NLog 公式サイトにある記述をそのまま使用しています。

<!-- ロガー名からターゲットにマップするルール -->
<rules>
  <!-- Microsoft からのものを含むすべてのログ -->
  <logger name="*" writeTo="TraceOutput" />

  <!-- 起動の検出を高速化するために、ホスティングライフタイムメッセージをコンソールターゲットに出力します。Microsoft.Hosting.Lifetime はここより下の定義には出力しません -->
  <logger name="Microsoft.Hosting.Lifetime" minlevel="Info" writeTo="LifetimeConsole" final="true" />

  <!-- 重要でない Microsoft ログをスキップして、自分のログのみをログに記録する。システムが出す Warning 以上のログ以外はここより下の定義には出力されません -->
  <logger name="Microsoft.*" maxlevel="Info" final="true" />
  <logger name="System.Net.Http.*" maxlevel="Info" final="true" />

  <!-- 上記で除外したもの以外をファイルに出力 -->
  <logger name="*" writeTo="FileOutput" />
</rules>

ここではどのレベル、どの種類のログをどこに出力させるかを指定します。この記述は上から順番に適用されます。

一つ目は name="*" を指定しつつレベルを指定していないため、全てのログを writeTo のターゲットに出力します。ここでは target で作成した TraceOutput を指定しているので Visual Studio の出力に表示されます。

二つ目は Microsoft.Hosting.Lifetime のライブラリで出力されたログを writeTo (コンソール) に対して出力しています。 ConsoleLifetime 関連を Azure や Docker などのコンソールで確認することができます。 minlevel="Info" を指定しているので Trace や Debug のログは出力されません。また final="true" を指定しているので、これより後の定義には Microsoft.Hosting.Lifetime 関連のログは出力されません。

三つ目は name="Microsoft.*" と name="System.Net.Http.*" のログに対して final="true" を指定してログ出力を止めています。 name の「*」はワイルドカードであり、Microsoft と System.Net.Http 関連のライブラリすべてを指すことを意味しています。 maxlevel="Info" が指定されているので Trace, Debug, Information をここで止めますが、 WArning, Error, Critical のログは後続の定義でも出力されます。

四つ目は上で final="true" で止めたログ以外をファイルに出力しています。

ログをアーカイブする

メインのログファイルを一つだけにして日付ごとに古いログファイルを別フォルダにアーカイブしていく方法もあります。

例えば以下のようになります。

<target xsi:type="File"
        name="FileOutput"
        fileName="${aspnet-appbasepath}/Log.log"
        archiveNumbering="Date"
        archiveEvery="Day"
        archiveFileName="${aspnet-appbasepath}/Archive/Log_{#}.log"
        archiveDateFormat="yyyy-MM-dd"
        maxArchiveFiles="7"
        layout="${layoutDefine}" />

ここで使用しているパラメータは以下のような意味になります。

パラメータ	説明
archiveNumbering	Date を指定すると日付によってアーカイブファイルを作成します。
archiveEvery	Day を指定すると日単位でアーカイブします。「Month」「Hour」「Sunday」などの指定方法もあります。
archiveFileName	アーカイブ先のパスです。{#} の箇所はアーカイブ単位で変わります。
archiveDateFormat	日付ごとにアーカイブする際のファイル名の年月日フォーマットです。
maxArchiveFiles	最大何ファイルアーカイブするかを指定します。

また、日付以外の方法でもアーカイブする方法はあります。詳しくは 公式サイト を参照してください。

実行すると以下のようになります。

ログごとにメールを送信する

NLog ではログ出力時にメールを送信することも可能です。ただし、デバッグログなどをメールを送信してしまうと送信過多になってしまうため、 Error や Fatal などの限定的なログレベルのみを対象とするのがよいでしょう。また、送信のし過ぎによるメールサーバーのブロックなどの障害リスクを避けるために、ログ専用のメールアカウントを指定することをお勧めします。

以下は設定例です。実際にメールを送信する場合は使用する SMTP サーバーに従って設定してください。

<targets>
  <target xsi:type="Mail"
          name="SendMail"
          smtpServer="SMTP Server Name"
          smtpPort="25"
          subject="XXXX システムでエラーが発生しました"
          from="aaaa@example.com"
          to="bbbb@example.com"
          enableSsl="False"
          smtpAuthentication="None"
          smtpUserName=""
          smtpPassword=""
          layout="${layoutDefine}"/>
</targets>

<rules>
  <logger name="*" minlevel="Error" writeTo="SendMail" />
</rules>

ログをデータベースに書き込む

NLog ではログをデータベースに書き込むこともできます。以下は一つの例ですので詳しくは 公式サイト を参照してください。

ここでは別サーバーにある SQL Server に対して書き込む手順を説明します。

まずは対象の SQL Server にログ用のテーブルを作成します。書き込む値は選べるのでログとして必要なものを列として定義します。

以下はテーブル作成 SQL の例です。

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
CREATE TABLE [dbo].[Log](
  [Id] [int] IDENTITY(1,1) NOT NULL,
  [Application] [nvarchar](50) NOT NULL,
  [Logged] [datetime] NOT NULL,
  [Level] [nvarchar](50) NOT NULL,
  [User] [nvarchar](250) NOT NULL,
  [Message] [nvarchar](max) NOT NULL,
  [Logger] [nvarchar](250) NULL,
  [Callsite] [nvarchar](max) NULL,
  [Exception] [nvarchar](max) NULL,
  CONSTRAINT [PK_dbo.Log] PRIMARY KEY CLUSTERED 
(
  [Id] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]
GO

データベース処理を行うには System.Data.SqlClient のデータベースクライアントライブラリが必要です。 NuGet からインストールしましょう。

appsettings.json にデータベース情報を書き込みます。 nlog.config では appsettings.json にある情報を読み込むことができます。設定内容は仮ですので、実際のデータベースに合わせて設定してください。キー名は任意ですが、nlog.config の方で指定する際に使用します。

{
  "": "省略",

  "NlogConnection": {
    "DbHost": "ServerName\\SQLEXPRESS",
    "Database": "TestDatabase",
    "User": "UserName",
    "Password": "********"
  }
}

nlog.config は以下のように設定します。

<targets>
  <target xsi:type="Database"
          name="DatabaseOutput"
          dbProvider="sqlserver"
          dbHost="${configsetting:name=NlogConnection.DbHost}"
          dbDatabase="${configsetting:name=NlogConnection.Database}"
          dbUserName="${configsetting:name=NlogConnection.User}"
          dbPassword="${configsetting:name=NlogConnection.Password}">
    <commandText>
      insert into dbo.Log (
        Application, Logged, [Level], [User], Message, Logger, CallSite, Exception
      ) values (
        @Application, @Logged, @Level, @User, @Message, @Logger, @Callsite, @Exception
      );
    </commandText>
    <parameter name="@application" layout="XXXX System" />
    <parameter name="@logged" layout="${date}" />
    <parameter name="@level" layout="${level}" />
    <parameter name="@user" layout="${aspnet-user-identity}" />
    <parameter name="@message" layout="${message}" />
    <parameter name="@logger" layout="${logger}" />
    <parameter name="@callSite" layout="${callsite:filename=true}" />
    <parameter name="@exception" layout="${exception:tostring}" />
  </target>
</targets>

<rules>
  <logger name="*" writeTo="DatabaseOutput" />
</rules>

実行してエラーがなければ以下のように書き込まれます。

ちなみに Program.cs の CreateHostBuilder メソッドの前など、早い段階でログをデータベースに書き出そうとすると失敗する場合がありますので注意してください。

RequestServices からロガーを取得してログを出力する

新しいコントローラーやページモデルを作成するたびにコンストラクタに ILogger を追加するのが面倒な場合があります。別の方法としては RequestServices から取得する方法もあります。

public void OnGet()
{
  // RequestServices から ILogger を取得する
  var logger = (ILogger<IndexModel>)HttpContext.RequestServices.GetService(typeof(ILogger<IndexModel>));

  logger.LogInformation("ページを表示するタイミングでログを出力します。");
}

自身のコントローラーやページモデルを指定するのも面倒であれば、拡張メソッドを作る方法や基本クラスを作成する方法もあります。

public static class AspNetExtention
{
  /// <summary>
  /// ロガーを取得する拡張メソッドです。
  /// </summary>
  public static ILogger<T> GetLogger<T>(this T self) where T : PageModel
    => (ILogger<T>)self.HttpContext.RequestServices.GetService(typeof(ILogger<T>));

  // MVC の場合
  //public static ILogger<T> GetLogger<T>(this T self) where T : Controller
  //  => (ILogger<T>)self.HttpContext.RequestServices.GetService(typeof(ILogger<T>));
}

使用例

public void OnGet()
{
  // RequestServices から ILogger を取得する (this. は必要)
  var logger = this.GetLogger();

  logger.LogInformation("ページを表示するタイミングでログを出力します。");
}

Cookie 認証を使用してログインしないとリダイレクトされる仕組みを作る (ASP.NET Core 3.0)

キャッシュされた古いバージョンの静的ファイルが使用されないように最新であることを示すバージョンを付加する