.NETで作る!

.NETに関するあれこれ(C#、VB.NET)

NLog LayoutRendererを自作する

はじめに

NLog の使い方は一般的に

logger.info("メッセージ")

になりますが、「メッセージ(文字列)」しか指定できません。 通常はこれで問題はないのですがそれ以外の情報も出力したいことがあります。

通常のコード

例えば、SQLのロギングを考えてみます。以下のような情報も出したいですね。

開始時なら

終了時なら

  • 実行時間

では、この場合のロギングコードを書いてみます。

logger.info("開始 | {0}", sql)
Dim sw As New Stopwatch
sw.Start()
'SQLの実行
sw.Stop()
logger.info("終了 | {0:n0}msec", sw.ElapsedMilliseconds)

一見何も問題はないですが、ステータスの情報とそれ以外の情報をくっつけて渡してしまっています。 今後処理時間が遅いSQL文だけを調べようと思ってもメッセージから処理時間を切り出し(文字列分解)しないといけないので、分析には不向きです。 また区切り文字を「|」にしてしますが、本来区切り文字はconfigのlayoutで制御すべきです。これも分析には不向きになってしまいます。

LayoutRendererを自作する

上記の問題はLayoutRendererを自作することで解決します。 LayoutRendererっていうのは端的に言えば「${logger}」、や「${message}」のことです。

今回は「${status}」というLayoutRendererを作って開始、終了の情報をメッセージから切り出してみます。

StatusLayoutRenderer.vb

Imports System.Runtime.CompilerServices
Imports System.Text
Imports NLog
Imports NLog.LayoutRenderers

<LayoutRenderer("status")>
Public Class StatusLayoutRenderer
    Inherits LayoutRenderer

    Protected Overrides Sub Append(builder As StringBuilder, logEvent As LogEventInfo)
        If logEvent.Exception IsNot Nothing Then
            builder.Append("excep")
            Return
        End If

        Dim name As String = "status"
        If logEvent.Properties.ContainsKey(name) = False Then Return
        builder.Append(logEvent.Properties(name))
    End Sub

    Public Enum Statuses
        Start
        [End]
        Exception
    End Enum
End Class

Public Module LogEventInfoExtension
    <Extension>
    Public Sub SetStatus(source As LogEventInfo, value As StatusLayoutRenderer.Statuses)
        source.Properties("status") = value
    End Sub
End Module

Module1.vb

Imports NLog

Module Module1


    Private logger As NLog.Logger = NLog.LogManager.GetCurrentClassLogger

    Sub Main()
        Action1()
        Action2()
    End Sub

    Private Sub Action1()
        Dim evt As New LogEventInfo
        evt.Properties("status") = StatusLayoutRenderer.Statuses.Start
        logger.Info("開始しました", evt)

        'TODO:なにかの処理

        evt.Properties("status") = StatusLayoutRenderer.Statuses.End
        logger.Info("終了しました", evt)
    End Sub

    Private Sub Action2()
        Dim evt As New LogEventInfo
        evt.SetStatus(StatusLayoutRenderer.Statuses.Start)
        logger.Info("開始しました", evt)

        'TODO:なにかの処理

        evt.SetStatus(StatusLayoutRenderer.Statuses.End)
        logger.Info("終了しました", evt)
    End Sub
End Module

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"
      xsi:schemaLocation="http://www.nlog-project.org/schemas/NLog.xsd NLog.xsd"
      autoReload="true"
      throwExceptions="false"
      internalLogLevel="Off"
      internalLogFile="logs/nlog-internal.log" >

  <extensions>
    <!--TODO:自作クラスがあるアセンブリ名を記述してください-->
    <add assembly="NlogCustomLayoutRenderer"/>
  </extensions>
  
  <targets>
    <target name="debugger" xsi:type="Debugger"
            header="${splitter}${newline}${processname} ver.${assembly-version}"
            layout="${date:format=HH\:mm\:ss.fff} | ${pad:padding=-5:inner=${level:uppercase=true}} | ${logger:shortName=true:padding=30} | ${pad:padding=-9:inner=${status:uppercase=true}} | ${replace-newlines:${message}}${onexception:inner=${newline}${exception}"
            />
  </targets>

  <rules>
    <logger name="*" minlevel="Trace" writeTo="debugger" enabled="true" />
  </rules>
</nlog>

実行結果

22:24:22.560 | INFO  |                        Module1 | START     | 開始しました
22:24:22.673 | INFO  |                        Module1 | END       | 終了しました
22:24:22.680 | INFO  |                        Module1 | START     | 開始しました
22:24:22.680 | INFO  |                        Module1 | END       | 終了しました

ミソ

logger.info("メッセージ")

と書くところを

Dim evt As New LogEventInfo
evt.Properties("属性名") = 属性値
logger.Info("メッセージ", evt)

って書くところがミソ。 そうすることでLayoutRendererに情報が渡せるので、あとはその情報を取り出しアウトプットするクラスを作ってやるだけ。

注意点はカスタム処理を入れていることをNLogに通知させるために、NLogのConfigに以下のコードを書くのを忘れない。

<extensions>
  <!--TODO:自作クラスがあるアセンブリ名を記述してください-->
  <add assembly="NlogCustomLayoutRenderer"/>
</extensions>

ちなみにアセンブリの名称を「NLog.*」にすると上記のConfigを書かなくてもよかったはず。

参考

github.com

. .