Moq Verify Not Working as Expected After Upgrading to .NET Core 3.1

Viewed 601

So as the title implies, this worked for us in .NET Core 2.2 and Moq Version 4.10.1. After upgrading to .NET Core 3.1 and Moq Version 4.14.5, the verify method is failing saying the method specified hasn't been called (no changes to the underlying code). I rolled back Moq to version 4.10.1 just to see if it was due to a change within the new version of Moq. I still get the same error.

Trying to verify that a log message has been written to the ILogger.

Weird thing is, if I debug the unit test and look at the mocked object with a variable watch, it shows that the method has indeed been invoked.

enter image description here

Relevant code:

public class AuditFilter, IResultFilter
{
    ...     
    public void OnResultExecuted( ResultExecutedContext context )
    {
        if( !IsContextValid( context ) )
        { return; }
        ...
    }
    
    public override bool IsContextValid( FilterContext context )
    {
        if( context == null )
        { 
            Logger.Error( "Error writing to the audit log", new ArgumentNullException( nameof( context ) ) ); 
            return false;
        }

        if( context.HttpContext == null )
        { 
            Logger.LogError( "Error writing to the audit log", new ArgumentNullException( nameof( context.HttpContext ) ) );
            return false;
        }

        return true;
    }       

    public ILogger Logger { get; set; }
    ...
}

public class AuditTests : BaseTests
{
    ...     
    private Mock<ILogger> _mockLog;
    private AuditFilter _filter;

    [SetUp]
    public void Setup()
    {
        _mockLog = new Mock<Microsoft.Extensions.Logging.ILogger>();
        _mockLog.SetupAllProperties;
        _filter = new AuditFilter();
    }

    [Test]
    public void Service_Filters_Audit_IsContextValid_Context_Null()
    {
        var expected = false;
    
        _filter.Logger = _mockLog.Object;
        var actual = _filter.IsContextValid( null );
    
        _mockLog.Verify( logger => logger.Log( LogLevel.Error, 
            It.IsAny<EventId>(), 
            It.IsAny<object>(),
            It.IsAny<ArgumentNullException>(), 
            It.IsAny<Func<object, Exception, string>>() ),
            Times.Once );
    
        Assert.AreEqual( expected, actual );
    }       
    ...
}

Note: The method ILogger.LogError is a Microsoft extension method for ILogger that calls ILogger.Log method.

Below is the exception that is thrown. enter image description here

Note: An integer implicitly casts to Microsoft.Extensions.Logging.EventId, the second input parameter type for the ILogger.Log method.

These signatures appear to match to me; so I'm not sure why it's saying it wasn't invoked.

To reiterate, this code worked prior to upgrading to .NET Core 3.1 and still works in our pre-forked code.

Also, before someone suggests that the method needs to be setup: it worked before the upgrade without it, and I already tried it and it didn't work.

2 Answers

I believe the problem will be this part of the verify expression

It.IsAny<Func<object, Exception, string>>()

Under the covers it's not a Func<object, Exception, string> and the mock IsAny matcher doesn't match because of this difference. If you modify it to

(Func<object, Exception, string>) It.IsAny<object>()

it should match. Below is what I've settled on as the starting point for verify expressions as it works for at least .NET Core 2.* onwards:

loggerMock.Verify(x => x.Log(
      It.IsAny<LogLevel>(),
      It.IsAny<EventId>(),
      It.IsAny<IReadOnlyList<KeyValuePair<string, object>>>(),
      It.IsAny<Exception>(),
      (Func<object, Exception, string>) It.IsAny<object>()),
   Times.Exactly(expectedNumberOfInvocations));

You can use It.IsAny<object>() for the third parameter but I find this is more convenient when interrogating the properties.

I've been doing a fair bit of log invocation verification at work recently for black box processes so now I mostly use Moq.Contrib.ExpressionBuilders.Logging to build fluent, readable verify expressions. Disclaimer: I am the author.

Like I had added in the comments, this is a known issue with Moq and .NET Core right from the Preview version of .NET Core 3.0. Please take a look at the github issue to understand why this broke with the update.

In a nutshell, from the issue linked, the failure here is caused due to fact that the type being passed to Logger.Log method is now changed to FormattedLogValues. Though there is a generic type matcher It.IsAnyType introduced in Moq 4.13.0, that would not address the issue.

The reason for this, as one of the authors of Moq states here

The important bit (for now) is that It.IsAnyType is not used in a nested position in the It.IsAny<> type argument.

As a workaround we should replace It.IsAny<Func<object, Exception, string>>() with (Func<object, Exception, string>)It.IsAny<object>()

The rationale provided for this, is to improve the performance of the type matcher as the former would result in the decomposition of all the type parameters underneath the hood to see if there is a type matcher included in the first place.

Related