ユニットテストでログをキャプチャ

アプリケーションコードでは、主に診断目的のためにログ文を書くのに使用されます.たとえば、ログを使用して予期しないエラーフローをキャプチャします.したがって、私たちの単体テストでログ出力をキャプチャすることは珍しくありません.あなたは、私が言うことができる限り、単位テストでログ出力を扱う3つの特徴的なオプションを持っています.

Scenario
私たちのテストシナリオは、テスト(SET)のサービスまたはシステムです.我々は依存Microsoft Extensions 我々のログイン目的のために.テストフレームワークとして、我々は使用されますXunit .

public interface IEchoService
{
    Task<string> Echo(string input);
}

SETの初期実装は次のようになります.

public class EchoService : IEchoService
{
    private readonly ILogger<EchoService> _logger;

    public EchoService(ILogger<EchoService> logger)
    {
        _logger = logger;
    }

    public Task<string> Echo(string input)
    {
        _logger.LogInformation("echo was invoked");
        return Task.FromResult(input);
    }
}

この記事のために、上記のスニペットは十分以上です.しかし、実際のアプリケーションでは、私も入力をログすることを好む.しかしながら、単純なストリング内挿を使用するならば、我々はすぐにそれについてコード分析警告を得ます.ここで推奨するのは、high-performance logging . 私は、loggermessageパターンを実装することがかなりのビットプレートを必要とするのを常に見つけました.幸運にも.NET 6、これはずっと簡単です.私たちはgenerate 我々が必要とするすべてのボイラープレート.いつものように、この新しい機能については、Andrewロックすでにです.
適用後LoggerMessage SUTへの変更は、以下のスニペットのように見えます.これはクラスを動かすためにご注意くださいEchoService それは今、自己としてマークされますpartial .

public partial class EchoService : IEchoService
{
    private readonly ILogger<EchoService> _logger;

    public EchoService(ILogger<EchoService> logger)
    {
        _logger = logger;
    }

    public Task<string> Echo(string input)
    {
        //_logger.LogInformation("echo was invoked");

        // The logging message template should not vary between calls to ... csharp(CA2254)
        // _logger.LogInformation($"echo was invoked with {input}");

        LogEchoCall(input);

        return Task.FromResult(input);
    }

    [LoggerMessage(1000, LogLevel.Information, "echo was invoked '{EchoInput}'")]
    partial void LogEchoCall(string echoInput);
}

Option 1
最初のアップは絶対に何もしていない.はい、あなたは正しくそれを読みます.最初のオプションで何もしないでこの作品を始めるのはばかげているかもしれませんが、テストコードのログ文で何もしていません.ヘック、何もしても2つの味が来る.
テストに依存性注入を使用する場合、"addloginging()"にアクセスできます.我々がログ記録プロバイダーを提供しないならば、我々のコードはちょうどうまく走ります.それ以外の場合は、既にログプロバイダーを設定したり、明示的に1つ提供している場合は、現在の設定に応じてゼロまたは複数のプロバイダにログオンします.たとえば、ConsoleLoggerProviderを使用して、テスト中にコンソールにログを記録できます.私はよく私のテストでDIバリアントを使用しています.なぜなら、iErviceCollectionの拡張メソッドを書いているので、とにかくコードを書くことができます.

[Fact]
public async Task Test_DependencyInjection_EmptyLoggingBuilder()
{
    var configuration = new ConfigurationBuilder().Build();
    var serviceProvider = new ServiceCollection()
        .AddLogging() // could also be part of AddEcho to make sure ILogger is available outside ASP.NET runtime
        .AddEcho(configuration)
        .BuildServiceProvider();
    var sut = serviceProvider.GetRequiredService<IEchoService>();
    var testInput = "Scenario: empty logging builder";
    var testResult = await sut.Echo(testInput).ConfigureAwait(false);
    testResult.Should().Be(testInput, "the input should have been returned");
}

[Fact]
public async Task Test_DependencyInjection_ConsoleLoggingBuilder()
{
    var configuration = new ConfigurationBuilder().Build();
    var serviceProvider = new ServiceCollection()
        .AddLogging(loggingBuilder => {
            loggingBuilder.AddConsole();
        })
        .AddEcho(configuration)
        .BuildServiceProvider();
    var sut = serviceProvider.GetRequiredService<IEchoService>();
    var testInput = "Scenario: console logging builder";
    var testResult = await sut.Echo(testInput).ConfigureAwait(false);
    testResult.Should().Be(testInput, "the input should have been returned");
}

しかし、テストの依存性の注入に依存できない場合は、SUTと関連する依存関係を作成するマニュアルを選択します.私たちのエコーサービスの唯一の依存関係はiloggerのインスタンスです.テスト目的の場合は、NullloggerFactoryを使用して、voidにログオンするロガーを作成します.

[Fact]
public async Task Test_Manuel_NullLoggingFactory()
{
    var sut = new EchoService(NullLogger<EchoService>.Instance);
    var testInput = "Scenario: null logger factory";
    var testResult = await sut.Echo(testInput).ConfigureAwait(false);
    testResult.Should().Be(testInput, "the input should have been returned");
}

As you can see in the screenshot above, and empty logger and a NullLogger are not the same thing.

Option 2
番目のメソッドは、それがIloggerの偽のバージョンであることを意味モックの背後にロガーを非表示にすることができますMoQフレームワークを使用します.私の前の記事では、私は私の好みの方法を書いたモックに触れました.私も、loggermockの初期のバージョンを含めました.それ以来、私はより多くの概念を肉食しているので、ここではロガーモックの更新版です.

public class LoggerMock<TCategoryName> : Mock<ILogger<TCategoryName>>
{
    private readonly List<LogMessage> logMessages = new();

    public ReadOnlyCollection<LogMessage> LogMessages => new(logMessages);

    protected LoggerMock()
    {
    }

    public static LoggerMock<TCategoryName> CreateDefault()
    {
        return new LoggerMock<TCategoryName>()
            .SetupLog()
            .SetupIsEnabled(LogLevel.Information);
    }

    public LoggerMock<TCategoryName> SetupIsEnabled(LogLevel logLevel, bool enabled = true)
    {
        Setup(x => x.IsEnabled(It.Is<LogLevel>(p => p.Equals(logLevel))))
            .Returns(enabled);
        return this;
    }

    public LoggerMock<TCategoryName> SetupLog()
    {
        Setup(logger => logger.Log(
            It.IsAny<LogLevel>(),
            It.IsAny<EventId>(),
            It.Is<It.IsAnyType>((v, t) => true),
            It.IsAny<Exception>(),
            It.Is<Func<It.IsAnyType, Exception?, string>>((v, t) => true)
        ))
        .Callback(new InvocationAction(invocation => {
            var logLevel = (LogLevel)invocation.Arguments[0];
            var eventId = (EventId)invocation.Arguments[1];
            var state = invocation.Arguments[2];
            var exception = (Exception?)invocation.Arguments[3];
            var formatter = invocation.Arguments[4];

            var invokeMethod = formatter.GetType().GetMethod("Invoke");
            var actualMessage = (string?)invokeMethod?.Invoke(formatter, new[] { state, exception });

            logMessages.Add(new LogMessage {
                EventId = eventId,
                LogLevel = logLevel,
                Message = actualMessage,
                Exception = exception,
                State = state
            });
        }));
        return this;
    }
}

任意Mock MOQで作成された能力は、模擬クラスになされた呼び出しを主張する能力を提供します.私のアプローチはモックステイタスを作るので、私はそれに対して作られた任意の要求をキャプチャすることができます.私たちは、情報にアクセスできるので、具体的な主張をすることができますEventId and LogLevel . たとえば、あなたがビジネスイベントに対して書かれたアラートを持っている場合は、正しい情報があなたのロギングシステムに渡すことを検証します.

[Fact]
public async Task Test_Moq_DefaultMockedLogger()
{
    var loggerMock = LoggerMock<EchoService>.CreateDefault();
    var sut = new EchoService(loggerMock.Object);
    var testInput = "Scenario: mocked logger";
    var testResult = await sut.Echo(testInput).ConfigureAwait(false);
    testResult.Should().Be(testInput, "the input should have been returned");

    loggerMock.LogMessages.Should().NotBeEmpty().And.HaveCount(1);
    loggerMock.VerifyEventWasLogged(new EventId(1000));
}

[Fact]
public async Task Test_Moq_LogLevelDisabledMockedLogger()
{
    var loggerMock = LoggerMock<EchoService>.CreateDefault().SetupIsEnabled(LogLevel.Information, enabled: false);
    var sut = new EchoService(loggerMock.Object);
    var testInput = "Scenario: log level disabled mocked logger";
    var testResult = await sut.Echo(testInput).ConfigureAwait(false);
    testResult.Should().Be(testInput, "the input should have been returned");

    loggerMock.LogMessages.Should().BeEmpty();
}

Options 3
これまで、我々は外で働くオプションを議論しましたXunit . 第3の技術はXunit , しかし、その実装はXunit 私たちは今、XUnitのITestOutputHelper メカニズムほとんどの場合、我々は使用するITestOutputHelper テストケース自体の行をログ出力するにはしかし、作成することが可能ですILogger それでITestOutputHelper それで、我々は我々のsutが生産するログを捕えることもできます.
マイクロソフトwell-written documentation カスタムロガープロバイダーを作成する方法.我々の設定クラスから始めるXunitLogger . 我々はこのデモでカスタム設定を持っていませんが、場所に配置を置くことは後で設定を簡単に追加することができます.The ConsoleLogger , たとえば、設定を使用してlogscopeの包含とタイムスタンプ形式を制御します.

public class XunitLoggerConfiguration
{
}

次は私たちのXUnitロガーそのものです.docsからのcoloredconsoleサンプルはスコープで何もしません、しかし、後で私たちを制限しないために、私たちは2009年の実装を変えましたBeginScope 使うIExternalScopeProvider . ログ行を印刷するには、Log<TState> , フォーマッタです.それから、xunitのitestoutputcapture output . 特定のニーズに応じて、ロガーのカテゴリ(名前)、イベント、ログレベル、スコープ、あるいは例外をログに記録できます.今のところ、シンプルにしましょう.

public class XunitLogger : ILogger
{
    private readonly string _loggerName;
    private readonly Func<XunitLoggerConfiguration> _getCurrentConfig;
    private readonly IExternalScopeProvider _externalScopeProvider;
    private readonly ITestOutputHelper _testOutputHelper;

    public XunitLogger(string loggerName, Func<XunitLoggerConfiguration> getCurrentConfig, IExternalScopeProvider externalScopeProvider, ITestOutputHelper testOutputHelper)
    {
        _loggerName = loggerName;
        _getCurrentConfig = getCurrentConfig;
        _externalScopeProvider = externalScopeProvider;
        _testOutputHelper = testOutputHelper;
    }

    public IDisposable BeginScope<TState>(TState state) => _externalScopeProvider.Push(state);

    public bool IsEnabled(LogLevel logLevel) => LogLevel.None != logLevel;

    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
    {
        if (!IsEnabled(logLevel))
        {
            return;
        }

         var message = formatter(state, exception);
         _testOutputHelper.WriteLine(message);
    }
}

安ILoggerProvider 作成に責任がありますILogger インスタンスつまり、カスタムも必要ですXunitLoggerProvider 世話をするXunitLogger .

public sealed class XunitLoggerProvider : ILoggerProvider
{
    private readonly IDisposable _configurationOnChangeToken;
    private XunitLoggerConfiguration _currentConfiguration;
    private readonly ConcurrentDictionary<string, XunitLogger> _loggers = new();
    private readonly IExternalScopeProvider _externalScopeProvider = new LoggerExternalScopeProvider();
    private readonly ITestOutputHelper _testOutputHelper;

    public XunitLoggerProvider(IOptionsMonitor<XunitLoggerConfiguration> optionsMonitor, ITestOutputHelper testOutputHelper)
    {
        _currentConfiguration = optionsMonitor.CurrentValue;
        _configurationOnChangeToken = optionsMonitor.OnChange(updatedConfiguration => _currentConfiguration = updatedConfiguration);
        _testOutputHelper = testOutputHelper;
    }

    public ILogger CreateLogger(string categoryName)
    {
        var logger = _loggers.GetOrAdd(categoryName, name => new XunitLogger(name, GetCurrentConfiguration, _externalScopeProvider, _testOutputHelper));
        return logger;
    }

    public void Dispose()
    {
        _loggers.Clear();
        _configurationOnChangeToken.Dispose();
    }

    private XunitLoggerConfiguration GetCurrentConfiguration() => _currentConfiguration;
}

最後のパズルピースは、新しいロガータイプを登録できる拡張メソッドです.また、ITestOutputHelper LoggingBuilderのDIコンテナにそういうわけでXunitLoggingProvider 前のスニペットでは、依存インジェクションコンテナからそれを取得できます.

public static class XunitLoggingBuilderExtensions
{
    public static ILoggingBuilder AddXunit(this ILoggingBuilder builder, ITestOutputHelper testOutputHelper)
    {
        builder.AddConfiguration();

        builder.Services.TryAddSingleton(testOutputHelper);

        builder.Services.TryAddEnumerable(
            ServiceDescriptor.Singleton<ILoggerProvider, XunitLoggerProvider>());

        LoggerProviderOptions.RegisterProviderOptions
            <XunitLoggerConfiguration, XunitLoggerProvider>(builder.Services);

        return builder;
    }

    public static ILoggingBuilder AddXunit(this ILoggingBuilder builder, ITestOutputHelper testOutputHelper, Action<XunitLoggerConfiguration> configure)
    {
        builder.AddXunit(testOutputHelper);
        builder.Services.Configure(configure);

        return builder;
    }
}

使用方法は以前に行ったCompileloggerの例と同じです.

[Fact]
public async Task Test_Custom_XunitLoggingBuilder()
{
    var configuration = new ConfigurationBuilder().Build();
    var serviceProvider = new ServiceCollection()
        .AddLogging(loggingBuilder => {
            loggingBuilder.AddXunit(_testOutputHelper);
        })
        .AddEcho(configuration)
        .BuildServiceProvider();
    var sut = serviceProvider.GetRequiredService<IEchoService>();
    var testInput = "Scenario: custom logging builder";
    var testResult = await sut.Echo(testInput).ConfigureAwait(false);
    testResult.Should().Be(testInput, "the input should have been returned");
}

初めてこのテストを受けた時、私は困惑した.コンソールでのコンソール出力を見ることができました.迅速なGoogle検索私にもたらしたsolution . 私たちはdotnetテストランナーにそれを表示するように指示する必要がありますdotnet test --logger:"console;verbosity=detailed" . 彼らはもはや実行することができます全体のチームを伝えるdotnet test 本当の解決策ではなかった.幸いにも、我々は物事を簡素化することができますdotnet test --settings runsettings.xml .

<?xml version="1.0" encoding="utf-8" ?>
<RunSettings>
    <LoggerRunSettings>
        <Loggers>
            <Logger friendlyName="console" enabled="True">
                <Configuration>
                    <Verbosity>detailed</Verbosity>
                </Configuration>
            </Logger>
        </Loggers>
    </LoggerRunSettings>
</RunSettings>

しかし、明示的には--settings 毎回、何も解決しません.でMicrosoft Docs 解決策を見つけた.MSBuildを使うことができますRunSettingsFilePath , それは私たちの世話をする.我々が現在走るならばdotnet test 適切な出力を得る.例えば、あなたはDirectory.Build.props プロジェクトのルートに.

<Project>
  <PropertyGroup>
    <RunSettingsFilePath>$(MSBuildThisFileDirectory)runsettings.xml</RunSettingsFilePath>
  </PropertyGroup>
</Project>

Closing Thoughts
私はこのトピックについて書く最初のではない知っているが、私は主題に新鮮な洞察を提供することを望む.別のテクニックは、すべてのメリットがあります.私は他の機会にすべての3つを使用しており、nullloggerは多くの場合、実行可能なオプションであることを思い出させる.10から9回、あなたはおそらくテストするビジネスロジックを気にする.最後の残りの時間のために、私はよく知られているプログラミングの知恵を言うことができます.
いつものように、質問があれば、遠慮なく手を伸ばす.あなたの提案や選択肢がありますか?私は彼らについて聞いてみたい.
この記事の対応するソースコードはGitHub .
次回参照してくださいすべてのすべてに健康と幸せなコーディング滞在🧸!