【ワレコVisual Studio】NLogやNlog.Configを使ってログファイルに出力する【書けない場合の対策】

ワテの場合、C#でプログラミングをする場合にはNLogを良く使っている。

NLogとは、.NETプラットフォームで利用出来る高性能なロギングツールだ。

NLog – Advanced and Structured Logging for Various .NET Platforms

公式サイトはこの辺り。

NLog
nlog-project.org

GitHub - NLog/NLog: NLog - Flexible and Structured Logging for various .NET Platforms
NLog - Flexible and Structured Logging for various .NET Platforms - NLog/NLog
github.com

NLogは便利なのだが、よく遭遇するトラブルとしては、何らかのタイミングでログが出なくなる問題がある。

例えば、NLogのパッケージをNugetで更新したら、それ以降、ログがファイルに書き込まれなくなったなど。

自分では何も変更していないのに・・・

そんなトラブルをワテは数回経験した。

この記事では、NLogの基本的な使い方や、トラブルの場合のワテ流対策を紹介したい。

では、本題に入ろう。

なお、最近のワテはNLogは使わずにASP.NET Coreが標準で持っている手法でログファイル出力している。以下の記事を参照。

C#でNLogを使う
NLogでログが出ない場合の対策
1. ログファイルに出力されない問題でワテが試みた対策（効果無）
2. ログファイルに出力されない場合のワテの対策（効果有り）
まとめ

C#でNLogを使う

C#でNLogを使う場合はNuget Package Managerで必要なパッケージをインストールするのが良い。

例えば、ワテが作っているC#のコンソールアプリケーションの場合には、以下の三つのパッケージをインストールしている。

一番目の NLogパッケージはNlogの本体だ。

確か、NLogを使うにはこのパッケージだけで良い。

二番目の NLog.Configパッケージは必要なら入れる。

このパッケージをインストールすると、NLogの設定をそのプロジェクトのルートフォルダに作成した NLog.Config と言うテキストファイルで行う事が出来る。

三番目の NLog.Schemaパッケージは上の二つを入れたら一緒に入った。詳細は未確認だ。

さて、ワテの場合は、上の様にNLog.Configパッケージをインストールしているので、設定は NLog.Configファイルで行う。

ログファイル名や出力先フォルダ名などを指定している。

NLog.Config設定ファイルの書き方

NugetでNLog.Configパッケージをインストールすると、プロジェクトのフォルダに以下の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="c:\temp\nlog-internal.log">

  <!-- optional, add some variables
  https://github.com/nlog/NLog/wiki/Configuration-file#variables
  -->
  <variable name="myvar" value="myvalue"/>

  <!--
  See https://github.com/nlog/nlog/wiki/Configuration-file
  for information on customizing logging rules and outputs.
   -->
  <targets>

    <!--
    add your targets here
    See https://github.com/nlog/NLog/wiki/Targets for possible targets.
    See https://github.com/nlog/NLog/wiki/Layout-Renderers for the possible layout renderers.
    -->

    <!--
    Write events to a file with the date in the filename.
    <target xsi:type="File" name="f" fileName="${basedir}/logs/${shortdate}.log"
            layout="${longdate} ${uppercase:${level}} ${message}" />
    -->
  </targets>

  <rules>
    <!-- add your logging rules here -->

    <!--
    Write all events with minimal level of Debug (So Debug, Info, Warn, Error and Fatal, but not Trace)  to "f"
    <logger name="*" minlevel="Debug" writeTo="f" />
    -->
  </rules>
</nlog>

NLog.Configファイルの初期状態

初めて見る人は、物凄く難しそうに見えるに違い無い。

実は、ワテの場合、詳しい中身は余り理解していない。

ネット検索して、見様見真似で以下のようなNLog.Configファイルを作成している。

ワテの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="c:\temp\nlog-internal.log">
 
	<targets>
		<!--
		<target xsi:type="File" name="logfile" fileName="${basedir}/APP_Data/nlog/ワテのlogfile.txt"
            layout="${date:format=yyyyMMddHHmmss} ${message}" />
		-->
		<target xsi:type="File" name="logfile" fileName="ワテのlogfile.txt" encoding="UTF-8"
            layout="${date:format=yyyyMMddHHmmss} ${message}" />
 
		<target xsi:type="ColoredConsole" name="console"
            layout="${longdate} ${uppercase:${level}} ${message}" />
	</targets>
 
	<rules>
		<logger name="*" minlevel="Info" writeTo="logfile" />
		<logger name="*" minlevel="Trace" writeTo="console" />
	</rules>
</nlog>

ワテのNLog.Cnfigファイル

まあ要するに、

fileName="ワテのlogfile.txt"

の部分を追加している。

これで、ログファイルは実行プログラムと同じフォルダに出力される。

次に必要なのが、NLogのインスタンスを作成する作業だ。

ワテの場合は、プログラムの冒頭で以下の一行を入れて logger と言う変数を定義している。

 public static NLog.Logger logger = NLog.LogManager.GetCurrentClassLogger();

static なオブジェクトで定義しているが、newで作成する方式でも良いと思うが試していない。

ワテの場合は、使い回すオブジェクトはstaticで定義する事が多い。

理由は、単なる癖だ。

あとは、プログラム中で以下のコマンドを実行するとこのログファイルに書き込める。

logger.Info("この文字列をログファイルに書き込めれば成功だ。");

Info()以外には、

logger.Warn();

logger.Debug();

logger.Error();

logger.Fatal();

など、書き込むログデータの重要度合に応じて使い分ければ良いだろう。

ASP.NET MVCの場合のログファイル

ASP.NET MVCでもNLogを良く使う。

パソコンのlocalhost環境ならデバッガーを使ってプログラムを追う事が出来るが、サーバーに発行した状態でリモートデバッグするのは難しい（ワテはやった事が無い）。

でも、ローカルなパソコンなら正常動作するのに、サーバーに発行すると何か問題が発生して動かないなんて言う事態はたまにある。

そう言う場合には、怪しそうな場所を try-catch-finally で囲って、例外をキャッチしたらそれを NLog でファイル出力させる。

そのファイルを開けば何が起こったのかが分る。

まあ、原始的な手法ではあるが、デバッグには役立つ。

さて、APS.NET MVCの場合には、ログファイルの出力先はこんな風にしている。

<target xsi:type="File" name="logfile" fileName="${basedir}/APP_Data/nlog/ワテのlogfile.txt"
           layout="${date:format=yyyyMMddHHmmss} ${message}" />

まあ、ファイルのパスに “${basedir}/APP_DATA/nlog” を追加しただけだが。

${basedir}

は、ASP.NET の発行先のフォルダになる。

まあ、その辺りは好き好きなので、どこに出力しても良いだろう。

IIS_USRSとIUSRの書き込み権限が必要

ちなみに、ASP.NET MVCの場合には、”ワテのlogfile.txt” ファイルに対して、以下の二つのユーザーが書き込み権限が無いとログに出力されない。

IIS_USRS
IUSR

この両方のユーザーに書き込み権限が必要だったのか、どちらか一方だけで良かったのかは忘れた。

兎に角、ログが出ない場合には、この二つのユーザーにフルコントロールの権限を与えておくと良いだろう。

NLog.Configパッケージを更新時の注意事項

NLog.ConfigパッケージをNugetで更新するとNLog.Configファイルが上書きされるので要注意だ。

一応、確認画面が出るが、うっかりして上書きをＯＫしてしまうと元ファイルが消えてしまう。

なので、更新前にはNLog.Configファイルのコピーを作っておくと良い。

さて、これで無事にログファイルに書き込めるようになったのだが、何らかのタイミングでログが全く出なくなる問題に今まで何度か遭遇した事がある。

NLogでログが出ない場合の対策

例えばこんな問題に遭遇した。

C#のコンソールアプリで上記のようにNLog.Configファイルを追加して、いい感じでログファイルに出力出来ていた。

で、Nugetパッケージマネージャで何か新しい更新が出ていないかなあと思って確かめたら

NLog.Configパッケージの更新が出ていた。

もちろん現在使っているNLog.Configファイルが上書きされてしまわないように、事前にバックアップしておいた。

で、何気なく更新した。

そしてNLog.Configファイルを元に戻したのだが。

ところが、それ以降、ログが全く出ないのだ。

ログファイルに出力されない問題でワテが試みた対策（効果無）

まずはVisual Studioを一旦閉じて、再びそのプロジェクトを開いてみたが、全く効果なし。

次に試したのは、Nlogには以下の出力方法があるが、取り敢えず何でも出力するInfo()を試した。

logger.Trace("trace log message");
logger.Debug("debug log message");
logger.Info("info log message");
logger.Warn("warn log message");
logger.Error("error log message");
logger.Fatal("fatal log message");

それでもログファイルに一切書き込まれない。

でも、エラーメッセージなどは出ない。

次に試したのはWindows 10の再起動。

まあ、これもダメだった。

あかんがな。

で、Visual Studioで何かおかしな状況に遭遇した場合のお勧めの対策としてワテが良くやっている極秘の対策を試みた。