How to Test Logging with FakeLogger

I originally posted this post on my blog a couple of weeks ago. It's part of an ongoing series I've been publishing, called Unit Testing 101.

Starting with .NET 8.0, we have a better alternative for testing logging and logging messages. We don't need to roll our own mocks anymore. Let's learn how to use the new FakeLogger<T> inside our unit tests.

.NET 8.0 introduces FakeLogger, an in-memory logging provider designed for unit testing. It provides methods and properties, such us LatestRecord, to inspect the log entries recorded inside unit tests.

Let's revisit our post on unit testing logging messages. In that post, we used a Mock<ILogger<T>> to verify that we logged the exception message thrown inside a controller method. This was the controller we wanted to test,

using Microsoft.AspNetCore.Mvc;

namespace FakeLogger.Controllers;

[ApiController]
[Route("[controller]")]
public class SomethingController : ControllerBase
{
    private readonly IClientService _clientService;
    private readonly ILogger<SomethingController> _logger;

    public SomethingController(IClientService clientService,
                               ILogger<SomethingController> logger)
    {
        _clientService = clientService;
        _logger = logger;
    }

    [HttpPost]
    public async Task<IActionResult> PostAsync(AnyPostRequest request)
    {
        try
        {
            // Imagine that this service does something interesting...
            await _clientService.DoSomethingAsync(request.ClientId);

            return Ok();
        }
        catch (Exception exception)
        {
            _logger.LogError(exception, "Something horribly wrong happened. ClientId: [{clientId}]", request.ClientId);
            //      👆👆👆
            // Logging things like good citizens of the world...

            return BadRequest();
        }
    }
}

// Just for reference...Nothing fancy here
public interface IClientService
{
    Task DoSomethingAsync(int clientId);
}

public record AnyPostRequest(int ClientId);

Photo by Jatin Jangid on Unsplash

1. Creating a FakeLogger

Let's test the PostAsync() method, but this time let's use the new FakeLogger<T> instead of a mock with Moq.

To use the new FakeLogger<T>, let's install the NuGet package: Microsoft.Extensions.Diagnostics.Testing first.

Here's the test,

using FakeLogger.Controllers;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Testing;
//    👆👆👆
using Moq;

namespace FakeLogger.Tests;

[TestClass]
public class SomethingControllerTests
{
    [TestMethod]
    public async Task PostAsync_Exception_LogsException()
    {
        var clientId = 123456;

        var fakeClientService = new Mock<IClientService>();
        fakeClientService
            .Setup(t => t.DoSomethingAsync(clientId))
            .ThrowsAsync(new Exception("Expected exception..."));
        //               👆👆👆
        // 3...2...1...💣💥💥

        // Look, ma! 🙌 No mocks here...
        var fakeLogger = new FakeLogger<SomethingController>();
        //                   👆👆👆
        var controller = new SomethingController(
                                fakeClientService.Object,
                                fakeLogger);
                                // 👆👆👆

        var request = new AnyPostRequest(clientId);
        await controller.PostAsync(request);

        // Warning!!! ☢️☢️
        //var expected = $"Something horribly wrong happened. ClientId: [{clientId}]";
        //Assert.AreEqual(expected, fakeLogger.LatestRecord.Message);
        // Do not expect exactly the same log message thrown from PostAsync()

        // Even better: 🤩
        fakeLogger.VerifyWasCalled(LogLevel.Error, clientId.ToString());
        //         👆👆👆
    }
}

We needed a using for Microsoft.Extensions.Logging.Testing. Yes, that's different from the NuGet package name.

We wrote new FakeLogger<SomethingController>() and passed it around. That's it.

2. Asserting on FakeLogger

The FakeLogger<T> has a LatestRecord property that captures the last entry we logged. Its type is FakeLogRecord and contains a Level, Message, and Exception. And if no logs have been recorded, accessing LatestRecord will throw an InvalidOperationException with the message "No records logged."

But, for the Assert part of our test, we followed the lesson from our previous post on testing logging messages: do not expect exact matches of logging messages in assertions. Otherwise, any change in the structure of our logging messages will make our test break, even if the underlying business logic remains unchanged.

Instead of expecting exact matches of the logging messages, we wrote an extension method VerifyWasCalled(). This method receives a log level and a substring as parameters. Here it is,

public static void VerifyWasCalled<T>(this FakeLogger<T> fakeLogger, LogLevel logLevel, string message)
{
    var hasLogRecord = fakeLogger
        .Collector // 👈
        .GetSnapshot() // 👈
        .Any(log => log.Level == logLevel
                    && log.Message.Contains(message, StringComparison.OrdinalIgnoreCase));
                    // 👆👆👆

    if (hasLogRecord)
    {
        return;
    }

    // Output:
    //
    // Expected log entry with level [Warning] and message containing 'Something else' not found.
    // Log entries found:
    // [15:49.229, error] Something horribly wrong happened. ClientId: [123456]
    var exceptionMessage = $"Expected log entry with level [{logLevel}] and message containing '{message}' not found."
        + Environment.NewLine
        + $"Log entries found:"
        + Environment.NewLine
        + string.Join(Environment.NewLine, fakeLogger.Collector.GetSnapshot().Select(l => l));

    throw new AssertFailedException(exceptionMessage);
}

First, we used Collector and GetSnapshot() to grab a reference to the collection of log entries recorded. Then, we checked we had a log entry with the expected log level and message. Next, we wrote a handy exception message showing the log entries recorded.

Voilà! That's how to write tests for logging messages using FakeLogger<T> instead of mocks.

If we only want to create a logger inside our tests without asserting anything on it, let's use NullLogger<T>. But, if we want to check we're logging exceptions, like good citizens of the world, let's use the new FakeLogger<T> and avoid tying our tests to details like the log count and the exact log messages. That makes our tests harder to maintain. In any case, we can roll mocks to test logging.

---

Hey! I'm Cesar, a software engineer and lifelong learner. If you want to upgrade your unit testing skills, check my course: Mastering C# Unit Testing with Real-world Examples on Udemy. Practice with hands-on exercises and learn best practices by refactoring real-world unit tests.

Happy testing!