NLog を実際に利用するために、サンプルを作成した。サンプルでは「Window起動時のイベント発生順位」と同じ内容を実行してみた。気になる点があったので、自分でもテストしてみようと思いました。（イベントの実行順序が違うといったことではないです）

NLog を利用する手順

NLog を利用するためには、最初に NLog を NuGet からパッケージを追加します。

そのあと、基本的には 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"
      throwExceptions="true">
    <!-- throwExceptions:NLog の（主に設定に関する）例外をスローするので、本番環境では false にすること -->
    <targets>
        <target name="console" xsi:type="Console" />
        <target name="debugger" xsi:type="Debugger" layout="[${uppercase:${level:padding=-5}}]${date:format=HH\:mm\:ss.ffff}: ${message}${exception:format=tostring} (${callsite})" />
        <target name="file" xsi:type="File" fileName="logs/log.txt" layout="${level},&quot;${message}&quot;,&quot;${exception:format=tostring}&quot;,${longdate},${callsite:className=true:methodName=true}" />
    </targets>

    <rules>
        <logger name="*" minLevel="Trace" writeTo="debugger" />
        <logger name="*" minlevel="Debug" writeTo="file" />
    </rules>
</nlog>

nlog.config ファイルは、出力ディレクトリー（bin/Debug or bin/Release など）にコピーして配置しておかないとダメです。なので、ファイルプロパティを変更します。

ビルドアクション：「コンテンツ」
出力ディレクトリーにコピー：「新しい場合はコピーする」

Debugger

実際に NLog を利用してみると、Visual Studio の出力ウィンドウに情報をアウトプットしたいことが（わりとすぐに）わかりました。

通常だと、System.Diagnostics.Debug を利用して書き込むのですが、NLog の場合は　xsi:type を「Debugger」に設定します。

これだけでもいいのですが、NLog は出力した「細かい時間」、「呼び出し元」などの情報を簡単に利用できるし変形もできる。これを活用することで Debug よりもよりよい情報を出力できるようになる。なので、ターゲットの layout プロパティで出力するテキストのフォーマットを設定しておきます。

今回、デバッガーは以下のフォーマットを採用した。

[${uppercase:${level:padding=-5}}]${date:format=HH\:mm\:ss.ffff}: ${message}${exception:format=tostring} (${callsite})

[INFO ]16:29:59.0163: Loaded event called. (EventOrderTest.MainWindowViewModel..ctor)

ポイントは level は info や error といった文字が入るけど、このレベルの単語は最大５文字なので、５文字で padding すると横の長さを一定にできる。出力ウィンドウの情報は基本的に一時的なもので、目で見て確認することになる。なので、読みやすい形にしておくといい。

また、出力ウィンドウは、基本的に当日の間に読むので yyyy-MM-dd といった年月日の情報は不要になり、時間 HH:mm:ss.ffff だけでいい。

情報として一番低レベルな Trace は、出力ウィンドウだけを対象にした。

File

ファイルは、実行ファイルパスを基準にして、ログファイルが出力される。便利だと思ったのは、サンプルでは logs/log.txt を指定しているが logs フォルダーは存在していなくても自動的に生成できる。（C# System.IO.File クラスは、通常だとそんな融通してくれないので）とても便利。

サンプルでは、レイアウトに以下の形式を指定した。

${level},&quot;${message}&quot;,&quot;${exception:format=tostring}&quot;,${longdate},${callsite:className=true:methodName=true}

Info,"OnStartup called.","",2023-04-12 16:29:58.2224,EventOrderTest.App.OnStartup

要するにカンマで区切って、CSV ファイルとしても読み込めるようにした。EXCEL や emeditor など、CSV ファイルを読み込めるエディターがあると、一覧性が高くなるフォーマットです。

" は、特殊文字 " のことです。xml や xaml のようなファイルでは、特殊な書式で指定する場合があります。

ファイルの場合は level の表示を５文字に矯正するようなことはしていません。（一覧として見るので、そういう小細工が不要になる）

レベルによる出力の調整と、出力レイアウトを工夫すると NLog の効果・価値をわかりやすく高めることができる。

ソースコード上からの Logger アクセス

基本的には、以下を利用することになると思う。（クラス変数にしなくてもよいとは思う）

private static readonly NLog.Logger _Logger = NLog.LogManager.GetCurrentClassLogger();

静的なクラスから取得するようなやり方で DI を経由しないほうがよいと思う。（GetCurrentClassLogger は、rules の都合（name で利用する名前空間を指定できる）でどのクラスから呼ばれているのかを判断したいから）

こんな感じで、NLog の利用をはじめるだけならそれほど面倒はないと思いました。ただし、注意点もあると思いました。

レイアウトをあらかじめ決めておいたほうがいい
レベルをどのような使い分けをするのか運用ルールを決めておいたほうがいい
nlog.config のテンプレートファイルを用意しておいてもよい（ここが見えるのが嫌な場合はコーディングに埋め込んでしまうこと）

サンプル

「Window起動時のイベント発生順位」を見ていて、気になる点があったので、自分でもテストしてみました。

添付プロパティで、Initialized と Loaded と ContentRendered の発生順序をテストしています。テストして（やはり）わかったのですが、添付プロパティでは、Initialized を受け取るのは難しいと思いました。

と、いうのも Initialized イベントは View を new すると、すぐに発生してしまいます。DataContent の VM と連携するのは、通常だとそのあとになってしまうので補足できないです。（これが気になった点で、本当に添付プロパティでイベントを確認できるのか気になってテストしました）

これもログを見ればわかるのですが、Initialized は Loaded よりも時間的にもかなり早いところで呼ばれていて、Startup の実行と Loaded の時間だと前者のほうに近い。こんな感じで、イベント実行の並び順に加えて、実行時の ffff ミリ秒の情報を活用できると思いました。