Best way to test logging?

Question

My code logs with an ILogger like this:

public class Calculator
{
    private readonly ILogger _logger;

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

    public int Sum(int x, int y)
    {
        int sum = x + y;

        _logger.LogInformation("The sum of {x} and {y} is {sum}.", x, y, sum);

        return sum;
    }
}

Now I want to be sure, that when I call Sum(2,3) the LogInformation contains the numbers 2, 3 and 5. How to catch that in Xunit (Moq)?

rgvlee · Accepted Answer · 2020-05-12T09:03:50.770

If it was me, I'd use Moq.Contrib.ExpressionBuilders.Logging (disclaimer: I am the author) to build the expression. It's designed for this exact purpose and provides a simple, readable statement.

loggerMock.Verify(Log.With.LogLevel(LogLevel.Information).And.LogMessage("The sum of {x} and {y} is {sum}.").And.LoggedValue("x", 2).And.LoggedValue("y", 3).And.LoggedValue("sum", 5), Times.Once);

If you want to roll your own you will need to perform your verify on the Log method and match on the log level and the read only list that contains the message/logged values.

The log level is straightforward. To match on the message/logged values you need to add a matcher on the TState parameter (the 3rd parameter) as per below:

var loggerMock = new Mock<ILogger<Calculator>>();
var logger = loggerMock.Object;
var calculator = new Calculator(logger);

calculator.Sum(2, 3);

loggerMock.Verify(l => l.Log(
    It.Is<LogLevel>(x => x.Equals(LogLevel.Information)),
    It.IsAny<EventId>(),
    It.Is<It.IsAnyType>((o, t) =>
        ((IReadOnlyList<KeyValuePair<string, object>>)o).Last().Value.ToString().Equals("The sum of {x} and {y} is {sum}.") &&
        ((IReadOnlyList<KeyValuePair<string, object>>)o).Any(y => y.Key.Equals("x") && y.Value.Equals(2)) &&
        ((IReadOnlyList<KeyValuePair<string, object>>)o).Any(y => y.Key.Equals("y") && y.Value.Equals(3)) &&
        ((IReadOnlyList<KeyValuePair<string, object>>)o).Any(y => y.Key.Equals("sum") && y.Value.Equals(5))
    ),
    It.IsAny<Exception>(),
    (Func<It.IsAnyType, Exception, string>)It.IsAny<object>()),
Times.Once);

Under the covers TState is a FormattedLogValues object which implements IReadOnlyList<KeyValuePair<string, object>>. FormattedLogValues is internal in .NET Core 3.* so you can't access it. The last item is {OriginalFormat} which is the log message as provided to the logger.

Best way to test logging?

1 Answers1