Posts tagged with “dotnet”

Technical Note: Testing ILogger with NSubstitute

1. The Challenge

Directly verifying ILogger extension methods (e.g., _logger.LogError("...")) with NSubstitute is difficult. These methods resolve to a single, complex generic method on the ILogger interface, making standard Received() calls verbose and brittle.

void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter);

2. The Solution: Inspect the State Argument

The most robust solution is to inspect the state argument passed to the core Log<TState> method. When using structured logging, this state object is an IEnumerable<KeyValuePair<string, object>> that contains the full context of the log call, including the original message template.

3. Implementation: A Reusable Helper Method

To avoid repeating complex verification logic, create a static extension method for ILogger<T>.

LoggerTestExtensions.cs

using System;
using System.Collections.Generic;
using System.Linq;
using Microsoft.Extensions.Logging;
using NSubstitute;
using FluentAssertions;

public static class LoggerTestExtensions
{
    /// <summary>
    /// Verifies that a log call with a specific level and message template was made.
    /// </summary>
    /// <typeparam name="T">The type of the logger's category.</typeparam>
    /// <param name="logger">The ILogger substitute.</param>
    /// <param name="expectedLogLevel">The expected log level (e.g., LogLevel.Error).</param>
    /// <param name="expectedMessageTemplate">The exact message template string to verify.</param>
    public static void VerifyLog<T>(this ILogger<T> logger, LogLevel expectedLogLevel, string expectedMessageTemplate)
    {
        // Find all calls to the core Log method with the specified LogLevel.
        var logCalls = logger.ReceivedCalls()
            .Where(call => call.GetMethodInfo().Name == "Log" &&
                           (LogLevel)call.GetArguments()[0]! == expectedLogLevel)
            .ToList();

        logCalls.Should().NotBeEmpty($"at least one log call with level {expectedLogLevel} was expected.");

        // Check if any of the found calls match the message template.
        var matchFound = logCalls.Any(call =>
        {
            var state = call.GetArguments()[2];
            if (state is not IEnumerable<KeyValuePair<string, object>> kvp) return false;
            
            return kvp.Any(p => p.Key == "{OriginalFormat}" && p.Value.ToString() == expectedMessageTemplate);
        });

        matchFound.Should().BeTrue($"a log call with the message template '{expectedMessageTemplate}' was expected but not found.");
    }
}

4. How to Use in a Unit Test

Step 1: Arrange In your test, create a substitute for ILogger<T> and inject it into your System Under Test (SUT).

// In your test class
private readonly ILogger<MyService> _logger;
private readonly MyService _sut;

public MyServiceTests()
{
    _logger = Substitute.For<ILogger<MyService>>();
    _sut = new MyService(_logger);
}

Step 2: Act Execute the method that is expected to produce a log entry.

[Fact]
public void DoWork_WhenErrorOccurs_ShouldLogError()
{
    // Act
    _sut.DoWorkThatFails();

    // ...
}

Step 3: Assert Use the VerifyLog extension method for a clean and readable assertion.

    // Assert
    _logger.VerifyLog(LogLevel.Error, "An error occurred while doing work for ID: {WorkId}");
}

5. Key Advantages of This Approach

  • Robustness: It verifies the intent (the message template) rather than the final formatted string, making it resilient to changes in parameter values.
  • Readability: The test assertion _logger.VerifyLog(...) is clean, concise, and clearly states what is being tested.
  • Reusability: The extension method can be used across the entire test suite.
  • Precision: It correctly targets the specific log level and message, avoiding ambiguity.