MoqでILoggerが呼ばれたことを確認するテストのメモ

概要

ログが想定されているものが出力されているか確認するテストを行ったところ以下のエラーが出た。
ここでは、テストを通すためにはどうすればよいのか検討する。

System.NotSupportedException : Unsupported expression: x => x.LogWarning("test", new[] {  })
    Extension methods (here: LoggerExtensions.LogWarning) may not be used in setup / verification expressions.

結論

LogWarningは拡張メソッドであり、Moqは拡張メソッドをモックできないのが原因であった。
拡張先のメソッドをモックする必要があった。

引数が1つの場合

サンプルコード

using Microsoft.Extensions.Logging;
namespace FunctionApp1
{
    public class LogTest
    {
        public static bool LogWrite(ILogger logger)
        {
            logger.LogWarning("test");
            return true;
        }
    }
}

失敗したテストケース

using System;
using Xunit;
using FunctionApp1;
using Microsoft.Extensions.Logging;
using Moq;

namespace XUnitTestProject1
{
    public class UnitTest1
    {
        [Fact]
        public void Test_ログの確認_失敗()
        {
            var mock = new Mock<ILogger>();
            Assert.True(LogTest.LogWrite(mock.Object));
            mock.Verify(x => x.LogWarning("test"), Times.Once);
        }
    }
}

成功するテストケース

Bot Builder v4.5 のユニットテスト : IBot を継承するクラスのテストを見てみるとILoggerを使ったテストをしている。
ただ、Logのverifyの仕方が異なっていた。それに倣ってみる。

        [Fact]
        public void Test_ログの確認_成功()
        {
            var mock = new Mock<ILogger>();

            Assert.True(LogTest.LogWrite(mock.Object));
            mock.Verify(x => x.Log(
            LogLevel.Warning,
            It.IsAny<EventId>(),
            It.Is<object>(o => o.ToString() == "test"),
            null,
            It.IsAny<Func<object, Exception, string>>()), Times.Once);
        }

通った。
Log.Warningとやってること違うんだけど。

検討。

ここで、LogWarningの型定義を見に行く。

        public static void LogWarning(this ILogger logger, EventId eventId, string message, params object[] args);
        public static void LogWarning(this ILogger logger, EventId eventId, Exception exception, string message, params object[] args);
        public static void LogWarning(this ILogger logger, string message, params object[] args);
        public static void LogWarning(this ILogger logger, Exception exception, string message, params object[] args);

ついでにLogの型定義を見に行く。

        public static void Log(this ILogger logger, LogLevel logLevel, Exception exception, string message, params object[] args);
        public static void Log(this ILogger logger, LogLevel logLevel, EventId eventId, string message, params object[] args);
        public static void Log(this ILogger logger, LogLevel logLevel, string message, params object[] args);
        public static void Log(this ILogger logger, LogLevel logLevel, EventId eventId, Exception exception, string message, params object[] args);

成功パターンのと何か違うな。

こんどは、テストで使用したmockのLogの型を見てみる。

public interface ILogger {
  Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)

...なにか違うな。

テストの型の名前空間は、namespace Microsoft.Extensions.Logging
実際に使っている方の名前空間はnamespace Microsoft.Extensions.Loggingここは同じだが、、

public static class LoggerExtensions
  public static void Log(this ILogger logger, LogLevel logLevel, Exception exception, string message, params object[] args);

LoggerExtensions にいますね。
この辺踏まえて検索すると、以下のような文章が見つかった。

問題は、拡張メソッドをモックできないことです。これは、定義上、静的メソッドの単なるシンタティックシュガーであるためです。したがって、あなたがしなければならないのは、拡張メソッドが拡張している「thing」の基礎となる呼び出しをモックすることです。
Mocking ILogger with Moq

なるほど。

確認

引数が複数の場合

        public static bool LogWrite(ILogger logger)
        {
            logger.LogWarning("test a:{0} b:{1} c:{2}", "a", "b", "c");
            return true;
        }

上記のようにコードを修正して試してみる。
テストコードも合わせて書き直す。

        [Fact]
        public void Test_ログの確認_引数複数()
        {
            var mock = new Mock<ILogger>();

            Assert.True(LogTest.LogWrite(mock.Object));
            mock.Verify(x => x.Log(
            LogLevel.Warning,
            It.IsAny<EventId>(),
            It.Is<object>(o => o.ToString() == "test a:a b:b c:c"),
            null,
            It.IsAny<Func<object, Exception, string>>()), Times.Once);
        }

無事成功。
ちょっと心配になったので、失敗パターンも試してみる。

        [Fact]
        public void Test_ログの確認_引数複数_失敗()
        {
            var mock = new Mock<ILogger>();

            Assert.True(LogTest.LogWrite(mock.Object));
            mock.Verify(x => x.Log(
            LogLevel.Warning,
            It.IsAny<EventId>(),
            It.Is<object>(o => o.ToString() == "test a:a b:b c:d"),
            null,
            It.IsAny<Func<object, Exception, string>>()), Times.Once);
        }

ちゃんと以下のようにエラーになった。

Moq.MockException : 
    Expected invocation on the mock once, but was 0 times: x => x.Log<object>(LogLevel.Warning, It.IsAny<EventId>(), It.Is<object>(o => o.ToString() == "test a:a b:b c:d"), null, It.IsAny<Func<object, Exception, string>>())

    Performed invocations:

       Mock<ILogger:1> (x):

          ILogger.Log<object>(LogLevel.Warning, 0, test a:a b:b c:c, null, Func<object, Exception, string>)

拡張メソッドを試す

参考ページで、拡張メソッドを作っていたので試す。

検証用テスト対象

        public static bool LogWrite(ILogger logger)
        {
            logger.LogWarning("test a:{0} b:{1} c:{2}", "a", "b", "c");
            logger.LogInformation("test a:{0}", "1");
            logger.LogDebug("test");
            logger.LogDebug("test2");
            logger.LogDebug("test2");

            return true;
        }

検証用テストメソッド

using System;
using Xunit;
using FunctionApp1;
using Microsoft.Extensions.Logging;
using Moq;

namespace XUnitTestProject1
{
    public static class MyMockExtension
    {
        public static Mock<ILogger<T>> VerifyLogging<T>(this Mock<ILogger<T>> logger, string expectedMessage, LogLevel expectedLogLevel = LogLevel.Debug, Times? times = null)
        {
            times ??= Times.Once();

            Func<object, Type, bool> state = (v, t) => v.ToString().CompareTo(expectedMessage) == 0;

            logger.Verify(
                x => x.Log(
                    It.Is<LogLevel>(l => l == expectedLogLevel),
                    It.IsAny<EventId>(),
                    It.Is<It.IsAnyType>((v, t) => state(v, t)),
                    It.IsAny<Exception>(),
                    It.Is<Func<It.IsAnyType, Exception, string>>((v, t) => true)), (Times)times);

            return logger;
        }
    }

    public class UnitTest1
    {
        [Fact]
        public void Test_ログの確認_引数複数_拡張()
        {
            var loggerMock = new Mock<ILogger<LogTest>>();

            Assert.True(LogTest.LogWrite(loggerMock.Object));
            loggerMock.VerifyLogging("test a:a b:b c:c", LogLevel.Warning)
                .VerifyLogging("test a:1", LogLevel.Information)
                .VerifyLogging("test")
                .VerifyLogging("test2", LogLevel.Debug, Times.AtLeastOnce());
        }
    }
}

呼び出されることのみを確認

messageがnullのときは呼び出されることだけを確認するようにしてみた。

        public static Mock<ILogger<T>> VerifyLogging<T>(this Mock<ILogger<T>> logger, string expectedMessage = null, LogLevel expectedLogLevel = LogLevel.Debug, Times? times = null)
        {
            times ??= Times.Once();

            Func<object, Type, bool> state = (v, t) => v.ToString().CompareTo(expectedMessage) == 0;

            logger.Verify(
                x => x.Log(
                    It.Is<LogLevel>(l => l == expectedLogLevel),
                    It.IsAny<EventId>(),
                    It.Is<It.IsAnyType>((v, t) => expectedMessage == null ? true : state(v, t)),
                    It.IsAny<Exception>(),
                    It.Is<Func<It.IsAnyType, Exception, string>>((v, t) => true)), (Times)times);

            return logger;
        }

        [Fact]
        public void Test_ログの確認_引数複数_拡張()
        {
            var loggerMock = new Mock<ILogger<Mock>>();
            // ログの内容にかかわらず、呼び出されることのみ確認
            loggerMock.VerifyLogging(null, LogLevel.Warning);
            loggerMock.VerifyLogging(null, LogLevel.Debug, Times.Exactly(3));

            // 呼び出されないことの確認
            loggerMock.VerifyLogging(null, LogLevel.Error, Times.Never());
            loggerMock.VerifyLogging("testaaa", LogLevel.Warning, Times.Never());
            loggerMock.VerifyLogging("test", LogLevel.Information, Times.Never());
            // loggerMock.VerifyLogging("test", LogLevel.Debug, Times.Never()); これはログレベルが違うので失敗する
        }

参考

Bot Builder v4.5 のユニットテスト : IBot を継承するクラスのテスト
Mocking ILogger with Moq
moq quick start
Moq : Mocking Framework for .NET
拡張メソッド
Moq 実装メモ