LoginSignup
10
10

More than 1 year has passed since last update.

@mxProject

.NET Core 汎用ホスト（GenericHost）ログ出力の構成

Last updated at Posted at 2020-01-19

このドキュメントの内容

汎用ホスト（GenericHost）におけるログ出力の構成についてまとめます。

このドキュメントの内容は .NET Core 3.1 で確認しています。

既定のロガー

Host クラスの CreateDefaultBuilder メソッドの既定の動作では、Microsoft.Extensions.Logging.ILogger<T> 型のロガーが注入されます。T は注入先のサービスなどの型です。このロガーインスタンスには次の4つのログプロバイダが格納されており、ロガーに対して出力したログはこれらのプロバイダを経由してそれぞれの出力先に出力されることになります。

  • Microsoft.Extensions.Logging.Console.ConsoleLogger
    • コンソールに対してログを出力します。
    • ログレベルは Information です。
  • Microsoft.Extensions.Logging.Debug.DebugLogger
    • デバッグ出力に対してログを出力します。
    • ログレベルは Information です。
  • Microsoft.Extensions.Logging.EventSource.EventSourceLogger
    • ETW（Event Tracing for Windows）に対してログを出力します。
    • ログレベルは Debug です。
  • Microsoft.Extensions.Logging.EventLog.EventLogLogger
    • イベントログに対してログを出力します。
    • ログレベルは Warning です。

ログプロバイダの追加と削除

既定のログプロバイダを削除したり、任意のログプロバイダを追加するには、IHostBuilder.ConfigureLogging メソッドに実装します。

ホストの構成例
IHostBuilder builder = Host.CreateDefaultBuilder(args)
    .ConfigureLogging((HostBuilderContext context, ILoggingBuilder builder) =>
    {
        // ログプロバイダをクリア
        builder.ClearProviders();
        // コンソールログを追加
        builder.AddConsole();
        // デバッグログを追加
        builder.AddDebug();
        // イベントログを追加
        builder.AddEventLog();
        // イベントソースを追加
        builder.AddEventSourceLogger();
        // 独自のログプロバイダを追加
        builder.AddProvider(new SampleLoggerProvider());
    }
    );

コンソールログ

動作オプションを設定できるオーバーロードが定義されています。

ホストの構成例
IHostBuilder builder = Host.CreateDefaultBuilder(args)
    .ConfigureLogging((HostBuilderContext context, ILoggingBuilder builder) =>
    {
        builder.AddConsole((ConsoleLoggerOptions options) =>
        {
            options.Format = ConsoleLoggerFormat.Default;
            options.DisableColors = true;
        }
        );
    }
    );

イベントログ

出力先とフィルタを設定できるオーバーロードが定義されています。

ホストの構成例
IHostBuilder builder = Host.CreateDefaultBuilder(args)
    .ConfigureLogging((HostBuilderContext context, ILoggingBuilder builder) =>
    {
        builder.AddEventLog((EventLogSettings settings) =>
        {
            settings.LogName = "Application";
            settings.MachineName = Environment.MachineName;
            settings.SourceName = "GenericHostSample";
            settings.Filter = (string category, LogLevel level) => true;
        }
        );
    }
    );

イベントソース

AddEventSourceLogger メソッドにはオーバーロードは定義されていません。独自のイベントソースに出力するような場合はプロバイダを自作する必要があります。

独自のログプロバイダ

ILoggerProvider インターフェースを実装したプロバイダを定義し、AddProvider メソッドを使って登録します。

ホストの構成例
IHostBuilder builder = Host.CreateDefaultBuilder(args)
    .ConfigureLogging((HostBuilderContext context, ILoggingBuilder builder) =>
    {
        builder.AddProvider(new SampleLoggerProvider());
    }
    );

ILoggerProvider に定義されているメソッドは CreateLogger メソッドのみです。
IDisposable インターフェースから派生していますので、Dispose メソッドも実装する必要があります。
プロバイダクラスに対して ProviderAliasAttribute を定義しておくと、既定のプロバイダ同様、JSON構成ファイルでプロバイダに対するログレベルを設定できるようになります。

SampleLoggerProvider
[ProviderAlias("SampleLogger")]
public class SampleLoggerProvider : ILoggerProvider
{
    public SampleLoggerProvider() {}

    ILogger ILoggerProvider.CreateLogger(string categoryName)
    {
        return new SampleLogger(m_Name + "." + categoryName);
    }
    void IDisposable.Dispose()
    {
    }
}

ILogger インターフェースには BeginScope, IsEnabld, Log の3つのメソッドが定義されています。IsEnabld, Log はその名のとおりです。
BeginScope メソッドはある一連の処理のログを出力するときにその開始と終了にログを出力するための仕組みだと思うのですが、ヘッダー・フッターを出力する、インデントするなどの例しか思いつきませんでした。
参考：Using The ILogger BeginScope In ASP.NET Core

SampleLogger
public class SampleLogger : ILogger
{
    public SampleLogger(string name)
    {
        m_Name = name;
    }

    private readonly string m_Name;

    // 指定されたログレベルが出力対象かどうかを取得します。
    bool ILogger.IsEnabled(LogLevel logLevel)
    {
        return true;
    }
    // 指定されたログを出力します。
    void ILogger.Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
    {
        string message = (メッセージをフォーマット。割愛します。)
        WriteLogLine(message);
    }
    // 指定されたログを出力します。
    private void WriteLogLine(string message)
    {
        Console.WriteLine(new string('\t', m_ScopeLevel) + message));
    }

    // スコープのレベル
    // スレッドセーフは考慮していません
    private int m_ScopeLevel = 0;

    // スコープが開始されたときの処理を行います。
    IDisposable ILogger.BeginScope<TState>(TState state)
    {
        WriteLogLine($"Begin {state}");
        ++m_ScopeLevel;

        return new Scope<TState>(state, () =>
        {
            // スコープが終了されたときの処理
            if (m_ScopeLevel > 0) { --m_ScopeLevel; }
            WriteLogLine("End");
        });
    }
    // BeginScope の戻り値として返すオブジェクト。
    // dispose されたときにスコープの終了処理を行います。
    private struct Scope<TState> : IDisposable
    {
        internal Scope(TState state, Action onDispose)
        {
            m_State = state;
            m_OnDispose = onDispose;
        }
        private readonly TState m_State;
        private readonly Action m_OnDispose;

        void IDisposable.Dispose()
        {
            m_OnDispose?.Invoke();
        }
    }

}

上の SampleLogger のスコープを使ったログ出力の例です。スコープが閉じられるまでの間はインデントされます。

ログを出力するコード
using (var scope = logger.BeginScope("一連の処理"))
{
    logger.LogTrace($"[TRACE] {message}");
    logger.LogDebug($"[DEBUG] {message}");
    logger.LogInformation($"[INFO] {message}");
    logger.LogWarning($"[WARN] {message}");
    logger.LogError($"[ERROR] {message}");
    logger.LogCritical($"[CRITICAL] {message}");
}
出力されたログ（LogLevel.Traceは無効になっています）
Begin 一連の処理
	[DEBUG] ログメッセージ
	[INFO] ログメッセージ
	[WARN] ログメッセージ
	[ERROR] ログメッセージ
	[CRITICAL] ログメッセージ
End

なお、このような場合は ILoggingBuilder インターフェースに対する拡張メソッドを定義することが一般的です。こうすることによって本来外に見せる必要がないプロバイダクラスを見せないようにすることができます。

拡張メソッド
public static class SampleLoggerProviderExtension
{
    public static ILoggingBuilder AddSampleLogger(this ILoggingBuilder builder)
    {
        return builder.AddProvider(new SampleLoggerProvider());
    }
}
ホストの構成例
IHostBuilder builder = Host.CreateDefaultBuilder(args)
    .ConfigureLogging((HostBuilderContext context, ILoggingBuilder builder) =>
    {
        // builder.AddProvider(new SampleLoggerProvider());
        builder.AddSampleProvider();
    }
    );

ログレベル

Microsoft.Extensions.Logging.LogLevel 列挙体には次の7つの値が定義されています。一般的なロガーのログレベルとほぼ同じです。ロガーのログレベルは出力対象の最小レベルを意味し、例えば Information が設定されている場合は Information ～ Critical が出力対象になります。

列挙値 値
Trace 0
Debug 1
Information 2
Warning 3
Error 4
Critical 5
None 6

コードによるログレベルの設定

ILoggingBuilder.SetMinimumLevel メソッドを使って既定のログレベルを設定することができます。

ホストの構成例
IHostBuilder builder = Host.CreateDefaultBuilder(args)
    .ConfigureLogging((HostBuilderContext context, ILoggingBuilder builder) =>
    {
        // ログレベルを設定
        builder.SetMinimumLevel(LogLevel.Debug);
    }
    );
  • 既定で登録される4つのログプロバイダのうち、ConsoleLogger と DebugLogger にはログレベルが適用されました。EventSourceLogger と EventLogLogger には適用されませんでした。

JSON構成ファイルによるログレベルの設定

application.json や任意のJSON構成ファイルを使って、ログレベルを含むロガーの設定を行うことができます。

構成ファイルの例
{
  "Logging": {
    // 既定のログレベル
    "LogLevel": {
      "Default": "Information"
    },
    // ConcoleLoggerのログレベル
    "Console": {
      "LogLevel": {
        "Default": "Warning"
      }
    },
    // DebugLoggerのログレベル
    "Debug": {
      "LogLevel": {
        "Default": "None",
        "GenericHostSample": "Debug"
      }
    },
    // EventSourceLoggerのログレベル 反映されない？
    "EventSource": {
      "LogLevel": {
        "Default": "None"
      }
    },
    // EventLogLoggerのログレベル
    "EventLog": {
      "LogLevel": {
        "Default": "None"
      }
    }
  }
}

  • 既定のログレベルの他、Microsoft.Extensions.Logging で提供されている各ログプロバイダごとのログレベルを設定することができます。この例の "GenericHostSample" のようにカテゴリ（≒注入先の名前空間＋型名）ごとのログレベルを設定することもできます。これは後述するフィルタに相当します。

  • 既定で登録される4つのログプロバイダのうち、ConsoleLogger と DebugLogger と EventLoglogger にはログレベルが反映されました。EventSourceLogger には適用されませんでした。

ログフィルタ

コードによるログフィルタの設定

ILoggingBuilder.AddFilter メソッドを使ってログフィルタを設定することができます。

ホストの構成例
IHostBuilder builder = Host.CreateDefaultBuilder(args)
    .ConfigureLogging((HostBuilderContext context, ILoggingBuilder builder) =>
    {
        // カテゴリに対してフィルタを設定
        builder.AddFilter("System", LogLevel.Warning);
        builder.AddFilter("Microsoft", LogLevel.Warning);
        builder.AddFilter("GenericHostSample", LogLevel.Debug);

        // フィルタメソッドで設定（Func<string, string, LogLevel, bool>）
        builder.AddFilter((provider, category, level) =>
        {
            if (provider.EndsWith("ConsoleLoggerProvider"))
            {
                if (category.StartsWith("Microsoft"))
                {
                    return (level.CompareTo(LogLevel.Warning) >= 0);
                }
            }
            return true;
        });
    }
    );
  • 既定で登録される4つのログプロバイダのうち、ConsoleLogger と DebugLogger にはフィルタが適用されました。EventSourceLogger と EventLogLogger には適用されませんでした。フィルタメソッドで設定すると provider に ConsoleLoggerProvider と DebugLoggerProvider が指定された呼び出しは発生しましたが、EventSourceLoggerProvider と EventLogLoggerProvider が指定された呼び出しは発生しませんでした。

JSON構成ファイルによるログレベルの設定

  • ログレベルを設定する際に "Default" の代わりにカテゴリを設定すると、カテゴリに対してフィルタを設定したのと同じ意味になります。前述のログレベルの記述例を参照してください。

  • EventLogLogger にもフィルタが適用されました。

  • EventSourceLogger にもフィルタが適用されました。ログレベルは適用されませんでしたが、フィルタは適用されるようです。

構成ファイルの例
{
  "Logging": {
    // "GenericHostSample" で始まるカテゴリは Critical、それ以外は Debug
    // "Default"（＝ログレベル）は適用されない？
    "EventSource": {
      "LogLevel": {
        "Default": "Error",
        "GenericHostSample": "Critical"
      }
    },
    // "GenericHostSample" で始まるカテゴリは Critical、それ以外は Error
    "EventLog": {
      "LogLevel": {
        "Default": "Error",
        "GenericHostSample": "Critical"
      }
    }
  }
}

ETWに出力されたログの取得

LoggingEventSource クラスのページに EventListener を使ったログの取得方法が説明されています。

EventListener クラスを継承したリスナークラスを実装します。

MsExtLoggingEventListener
// using System.Diagnostics.Tracing;
// using Microsoft.Extensions.Logging.EventSource;

// Microsoft.Extensions.Logging.EventSourceLogger から出力されるログを取得するリスナー
public class MsExtLoggingEventListener : EventListener 
{
    // イベントソースが生成されたときの処理を行います。
    protected override void OnEventSourceCreated(EventSource eventSource) 
    {
        // EventSourceLogger は "Microsoft-Extensions-Logging" という名前のイベントソースにログを出力します。
        if (eventSource.Name == "Microsoft-Extensions-Logging") 
        {
            // この例では FormattedMessage イベントのすべてのログを有効にしています。
            EnableEvents(eventSource, EventLevel.Verbose, LoggingEventSource.Keywords.FormattedMessage);
        }
    }

    // ログが書き込まれたときの処理を行います。
    protected override void OnEventWritten(EventWrittenEventArgs eventData) 
    {
        // この例ではイベントデータの内容をコンソールに出力しています。
        Console.WriteLine($"EventId = {e.EventId}");
        Console.WriteLine($"EventName = {e.EventName}");
        Console.WriteLine($"Keywords = {e.Keywords}");
        Console.WriteLine($"Level = {e.Level}");
        Console.WriteLine($"Message = {e.Message}");
        if (e.PayloadNames != null)
        {
            for (int i = 0; i < e.PayloadNames.Count; ++i)
            {
                Console.WriteLine($"Payload[{e.PayloadNames[i]}] = {e.Payload[i]}");
            }
        }
    }
}

次のコードは上記のリスナーを使ってアプリケーションのログを取得する簡単な例です。

リスナーの利用例
class Program
{
    static async Task Main(string[] args)
    {
        // リスナーを生成
        using (var listener = new MsExtLoggingEventListener())
        {
            // イベントハンドラを使ってイベントソースが生成されたときの処理とログが書き込まれたときの処理を行うことも可能です。
            listener.EventSourceCreated += listener_EventSourceCreated;
            listener.EventWritten += listener_EventWritten;

            // アプリケーションの処理を実行
            // この中でイベントソースに対して出力されたログがリスナーによって取得されます
            await CreateHostBuilder(args).RunConsoleAsync();
        }
    }

    // イベントソースが生成されたときの処理を行います。
    static void listener_EventSourceCreated(object sender, EventSourceCreatedEventArgs e)
    {
        // 割愛
    }
    // ログが書き込まれたときの処理を行います。
    static void listener_EventWritten(object sender, EventWrittenEventArgs e)
    {
        // 割愛
    }
}

ETW の最も大きなメリットは out-process なログ出力（ログを発生させるプロセスとログを記録するプロセスを分離する）ができることだと思うのですが、残念ながらこの EventListener を使った方法は out-process には対応していないようです。
out-process なログ出力を実現する方法には EtwStream があります。私も以前に EtwStream の動作確認をしたことがあり、C# ETW（Event Tracing for Windows）からログを取得する で紹介しています。

まとめ

ログプロバイダとログレベル／フィルタを柔軟に構成できることがわかりました。ただ、EventLogger と EventSourceLogger 関連のやや不可解な挙動については情報の整理が必要であるとも感じました。

10
10
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
10
10