🐈

C#の単体テストにおいてILoggerのログをテスト出力に表示する方法

株式会社ジェイテックジャパン CTOの高丘 @tomohisaです。今回は、ユニットテストを書いている際にちょっと困る問題を解決するdotnetのパッケージを紹介します。

テストにおけるログの問題

C#のユニットテストのフレームワーク、xUnitを使用している際に、ログを表示する際に使うことのできる方法で、まず推奨されているものが、 ITestOutputHelperを使用する方法です。
こちらを使用すると、各テストケースの実行ログに、ログが表示されます。ただ、これには問題があり、テストクラスではなくライブラリ内に残るコードにはITestOutputHelperをDIしたコードを残すことができないと言う点です。実際の実行時にはITestOutputHelperをサービスに登録していないため、取得できないためです。
ですので、ライブラリ内では、以下の2つの方法でログを記録できます。

  1. ILoggerを使用したログの記録。
    ILoggerはdotnet標準のログの記録方法です。ログのレベルによって記録できたり、ログを書き出したクラスも記録されたりなど便利に使えます。これはログを残す方法として推奨されている方法です。
    しかし、テストの際にはこれは問題があり、各ユニットテストのテストログに、デフォルトではILoggerで記録したログが記録されないと言う問題があります。ですので、ユニットテスト実行中にライブラリ内で出力したログが確認できず、デバッグが行いにくいと言う問題があります。
  2. Console.WriteLine()を使用したデバッグ出力
    Console.WriteLine()を使うとどこでも文字列をコンソールに出力できます。この方法を使うと、テストをデバッグ実行した時に、テストログ内には含まれないのですが、コンソールに出力結果が表示されます。これによってログを見ることはできるのですが、ILoggerのように、ログのレベルによる切り分けはできませんし、テストログ内に出力を含めることもできないため、視認性が悪くなります。

このような問題があり、今までは必要な時だけ一時的にConsole.WriteLineを記述し、動作確認が終わったらConsole.WriteLineを削除するようにしていました。しかしどうしても効率の良くない方法でILoggerを使うことができればいいなと考えていました。今回、動作について考えていて実はILoggerをDIするときに、テストの時だけITestOutputHelperをラッパーするILoggerの実装を使えば、問題が解決できると考え探してみました。探していたことを行なってくれるnugetバッケージが見つかったため、使用してみたところうまくいきました。

テストにおいてILoggerを使用する方法

検索で出てきたのが以下の記事です。
https://bartwullems.blogspot.com/2022/04/xunit-log-ilogger-messages-to-test.html

この記事では、上記のテストフレームワークでの問題を解決するのに、MartinCostello.Logging.XUnitというNugetパッケージが紹介されていました。

このパッケージを使用すると、ILoggerを使用して出力したログが、ITestOutputHelperを使用して出力されて、テストの実行ログ内に記録できます。また、ログレベルの調整により、本番実行時に表示しないなどの調整も行うことができるため、ログ出力のコードを必要に応じてライブラリ内に残すことができます。使用方法は以下の通りです。

MartinCostello.Logging.XUnitの使用方法

1. Nugetパッケージのインストール

Nugetパッケージのインストールはコマンドライン、Visual Studio、Riderなどでそれぞれ違いますが、こちらをテストフレームワーク内に登録します。

2. サービスとして、MartinCostello.Logging.XUnitの登録をする

テスト内で、DIを設定する際に、AddXUnitを使用して、ITestOutputHelperをILoggerとして登録します。

  • 例1 TestOutputHelperをnewする場合 *
public class AggregateTest : IDisposable
{
    protected readonly IServiceProvider _serviceProvider;

    public AggregateTest()
    {
        var services = new ServiceCollection();
        // ReSharper disable once VirtualMemberCallInConstructor
        SetupDependency(services);
        
        ...

        var outputHelper = new TestOutputHelper();
        services.AddSingleton<ITestOutputHelper>(outputHelper);
        services.AddLogging(builder => builder.AddXUnit(outputHelper));
        _serviceProvider = services.BuildServiceProvider();

        ...
    }
    [Fact]
    public void SomeTest()
    {
        ...
    } 
}

上記のように、テストの初期化時にAddLoggingを行い、ITestOutputHelperを登録します。ITestOutputHelperに関しては、新規でnew TestOutputHelper()を行なって大丈夫です。

  • 例2 TestOutputHelperをコンストラクタから取得する場合 *
public class ProjectSekibanByTestTestBase : SekibanByTestTestBase
{
    private readonly ISekibanTestFixture _fixture = new TestBase<FeatureCheckDependency>.SekibanTestFixture();
    public ProjectSekibanByTestTestBase(ITestOutputHelper testOutputHelper, ISekibanServiceProviderGenerator serviceProviderGenerator)
    {
        _fixture.TestOutputHelper = testOutputHelper;
        IServiceCollection services = new ServiceCollection();
        services.AddSingleton<IConfiguration>(fixture.Configuration);

        ... 

        if (fixture.TestOutputHelper is not null)
        {
            services.AddSingleton(fixture.TestOutputHelper);
        }
        services.AddLogging(builder => builder.AddXUnit(_fixture.TestOutputHelper));

        ...

        services.BuildServiceProvider();
    }
}

xUnitのテストのコンストラクタでITestOutputHelperを取得できます。その場合、取得したTestOutputHelperAddLoggingに渡すことができます。

3. ライブラリ内では、ILoggerをDIで取得して使用する

ILoggerの使用方法に関しては、詳しくは説明しませんが、DIで取得して使用できます。注意点としては、ILoggerは出力元のクラスをログに出力するため、ジェネリックで出力元クラスをつけて生成する必要があります。

    public class Subscriber : IEventSubscriber<OrderSubmittedI>
    {
        private readonly ILogger<Subscriber> _logger;
        public Subscriber(ILogger<Subscriber> logger) => _logger = logger;

        public async Task HandleEventAsync(Event<OrderSubmittedI> ev)
        {
            _logger.LogInformation("{PayloadOrderSubmittedLocalTime}", ev.Payload.OrderSubmittedLocalTime);
            await Task.CompletedTask;
        }
    }

注意点

この方法を使用する場合、ILoggerが本番のコードに残ります。ですので、Web APIやコンソールアプリケーションでライブラリを使用するときに、AddLoggingを必ず行うことが必要になります。行わない場合は、ILogger<TClass>型が見つからないと言うエラーとなりますのでご注意ください。
dotnetのサービス登録に関しては、同じクラスに複数回登録した場合、後に実行したものが優先されます。ですからAddLogging()をライブラリ内でデフォルト登録しておいて、クラッシュするのを防ぐこともできるます。ただ、この場合、ライブラリの前に仮にログを登録していた場合、設定が上書きされてしまうこともありますのでご注意ください。

まとめ

効率よく開発、デバッグ、機能追加していく上でログは非常に重要になります。第一にユニットテストで機能を可能な限りテストして動作確認することが重要です。ライブラリやフレームワークでは、1つの機能が多くの開発者やユースケースで使用されるためです。
正直なところ、nugetパッケージを登録しないでデフォルトで今回実装したことができる(自分でILoggerのラッパーを描かなくて良い形)が理想です。もしその方法や他のログの良い方法がありましたらぜひ教えてください。

イベントソーシングフレームワーク「Sekiban」は、現在、CosmosDB、DynamoDBに両対応していて、社内の複数のプロジェクトで運用しながら、オープンソース化の準備を進めています。こちらも進展がありましたらTwitterやZennでも報告予定ですので、よろしければフォローしてお待ちください。

ジェイテックジャパンブログ

Discussion