1

I'm having trouble while implementing a test for an ILogger call match when a tested method throws an exception and I really can't understand what's the reason.

This is how looks like my test method:

public async Task My_test_method()
{
    //Arrange

    var _logger = Substitute.For<ILogger<MyType>>();
    var _mockedInnerService = Substitute.For<IMockedInnerService>();
    var _testedService = new TestedService(_mockedInnerService, _logger);

    var errorMessage = "Some problem";
    _mockedInnerService
        .When(async _self => await _self.SomeMethod(Arg.Any<string>(), Arg.Any<string>()))
        .Do(_self => throw new Exception(errorMessage));
    var expectedMessage = $"Error: {errorMessage}";
    var methodParameters = new List<Guid>() { Guid.NewGuid() };

    //Act
    var results = await _testedService.TestedCall(methodParameters);

    //Assert
    await _mockedInnerService
        .Received(1)
        .SomeMethod(Arg.Any<string>(), Arg.Any<string>());
    results
        .Should()
        .BeEmpty();
    _logger
        .Received(1)
        .LogError(Arg.Is<string>(message => message == expectedMessage));
}

And this is how looks like my tested method:

public async Task<IList<SomeObject>> TestedCall(IList<Guid> ids)
{

    IList<object> results = null;
    try
    {
        units = await _innerService.SomeMethod("arg", "arg");
    }
    catch (Exception e)
    {
        var msg = "Some problem";
        _logger.LogError(msg);
    }

    return results == null
        ? new List<object>()
        : results.Select(s => new SomeObject(s.Id, s.Code)).ToList();
}

The test is failing with this result:

Message: 
    NSubstitute.Exceptions.ReceivedCallsException : Expected to receive exactly 1 call matching:
        Log<Object>(Error, 0, [null], <null>, Func<Object, Exception, String>)
    Actually received no matching calls.
    Received 1 non-matching call (non-matching arguments indicated with '*' characters):
        Log<Object>(Error, 0, *Some problem*, <null>, Func<Object, Exception, String>)

Can you guys help me to understand what I'm doing wrong here?

Thanks

Diego Rafael Souza
  • 5,241
  • 3
  • 23
  • 62

1 Answers1

3

It looks like the ILogger<T>.LogError(string) method is actually an extension method. That means it will translate to a different call under the hood, which is the Log<Object>(Error, 0, [null], <null>, Func<Object, Exception, String>) that you are seeing in the output. This method call can have additional arguments, which may not be the same for every call to the extension method, and thus may differ between your actual call and your assertion call.

To fix it, you probably have to assert on the underlying method, and use Arg.Any<T>() to make it ignore the problematic arguments, which is probably the Func<Object, Exception, String> argument at the end.

Vera
  • 644
  • 5
  • 10
  • You're completely right, it is an extension method. I couldn't get the assert works using the underlying method (`.Log()`) as you've suggested. Every attempt resulted in a non-matching call either. I've changed the assert to `_logger.ReceivedWithAnyArgs().LogError("Some problem");` and it is working now. =/ I'm not happy with this, but it'll give me some time to move on by now. Thanks for answer – Diego Rafael Souza Apr 05 '20 at 21:51
  • I'm checking it as the answer once the extension method explains the problem. – Diego Rafael Souza Apr 05 '20 at 21:59
  • 1
    @DiegoRafaelSouza Not sure what you have already tried for the underlying method, but maybe you could try first using `Arg.Any()` for *all* arguments, and if that *does* work, work your way back replacing the arguments you *do* want to check with actual arguments one by one, to at least find the one that's causing problems? Otherwise, you probably have to check the implementation of the extension method to see if it is doing anything else, and that might be more trouble than its worth (assuming a third party library) unless you are going to have a lot of these tests. – Vera Apr 05 '20 at 22:06
  • 2
    For more information on this please see [NSubstitute issue #597](https://github.com/nsubstitute/NSubstitute/issues/597). – David Tchepak Apr 07 '20 at 00:15