CODEWITHSUNDEEP
c#.netunit-testing.net-corensubstitute
Nick Dichiaro
Nick Dichiaro

Reputation: 410

NSubstitute ILogger .NET Core

I am trying to write unit tests around my exception handling so that I can verify the my logger is properly logging the exception. I am using NSubstitute as a mocking framework and Microsoft.Extensions.Logging.ILogger I have to following for my test:

[Fact]
public void LogsExcpetionWhenErrorOccursInCreate()
{
   var newUser = new UserDataModel
   {
      FirstName = "Rick",
      MiddleName = "Jason",
      LastName = "Grimes",
      Email = "[email protected]",
      Created = new DateTime(2007, 8, 15)
   };
   var exception = new Exception("Test Exception");
   // configure InsertOne to throw a generic excpetion
   _mongoContext.InsertOne(newUser).Returns(x => { throw exception; });

   try
   {
      _collection.Create(newUser);
   }
   catch
   {
      // validate that the logger logs the exception as an error
      _logger.Received().LogError(exception.Message);
   }
}

to test the logging in the following method:

public UserDataModel Create(UserDataModel user)
{
     try
     {
          return MongoContext.InsertOne(user);                
     }
     catch(Exception e)
     {
           _logger?.LogError(e.Message);
           throw new DataAccessException("An error occurred while attempting to create a user.", e);
      }

}

My test fails with the following error:

Message: NSubstitute.Exceptions.ReceivedCallsException : Expected to receive a call matching:
    Log<Object>(Error, 0, Test Exception, <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, *Test Exception*, <null>, Func<Object, Exception, String>)

I'm not sure why this is failing because even in then error message the calls are the same.

Thanks in advance!

Update:

Here is the constructor for the test, this is where I am injecting the logger mock:

public UserCollectionTest()
{
   _mongoContext = Substitute.For<IMongoContext<UserDataModel>>();
   _logger = Substitute.For<ILogger>();
   // create UserCollection with our mock client
   _collection = new UserCollection(_mongoContext, _logger);
}

Upvotes: 27

Views: 24501

Answers (8)

JosBleuet
JosBleuet

Reputation: 21

Add Microsoft.Extensions.Logging.Abstractions nuget to your test project

Example using NSubstitute and FluentAssertions in you test:

logger = Substitute.For<ILogger<YourClassToTest>>();
    
logger.Received(1).Log(
    Arg.Is(LogLevel.Information),
    Arg.Any<EventId>(),
    Arg.Is<object>(o => o.ToString().Contains("A message!!!")),
    Arg.Any<Exception>(),
    Arg.Any<Func<object, Exception, string>>()
);

Upvotes: 2

Jess
Jess

Reputation: 25139

I am using .NET 8, MSTest 3, and NSubstitute 5.

It seems to just work now.

private ILogger<IRebatesApiClient> _logger = null!;

[TestInitialize]
public void TestInitialize()
{
    _logger = Substitute.For<ILogger<IPeanutsApiClient>>();
}

...

// Assert
_logger.Received().LogError(expectedMessage);

Upvotes: 0

Chris S
Chris S

Reputation: 101

Not sure if they changed something once again but this worked in 2024 with NSubstitute for asserting log message:

    Assert.Contains($"your log here", logger?.ReceivedCalls()?
                                             .SelectMany(x => x.GetArguments())?
                                             .Select(x => x?.ToString());

Upvotes: 4

ChrisO
ChrisO

Reputation: 5475

I created an extension method for situations where I just want to know that a certain type of log was called. This is useful to hide all the extra Arg.Any that clutters tests and makes them hard to read. It's working in .NET 7 with NSubstitute 5.1.0.

public static class LoggerTestExtensions
{
    public static void AnyLogOfType<T>(this ILogger<T> logger, LogLevel level) where T : class
    {
        logger.Log(level, Arg.Any<EventId>(), Arg.Any<object>(), Arg.Any<Exception>(),
            Arg.Any<Func<object, Exception?, string>>());
    }
}

It can be used like so

logger.Received(1).AnyLogOfType(LogLevel.Error);

Upvotes: 7

Manthan Makani
Manthan Makani

Reputation: 117

Use name space below

using NSubstitute.ExceptionExtensions;

And update code to throw exception instead of returning it.

_mongoContext.InsertOne(newUser).Throw(exception);

Upvotes: -1

Marcin
Marcin

Reputation: 3262

And here is my approach that is going a bit further. And extending Githhub issue.

First logger:

using Microsoft.Extensions.Logging;

public abstract class MockLogger<T> : ILogger<T>
{
    void ILogger.Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
    {
        var unboxed = (IReadOnlyList<KeyValuePair<string, object>>)state!;
        string message = formatter(state, exception);

        this.Log();
        this.Log(logLevel, message, exception);
        this.Log(logLevel, unboxed.ToDictionary(k => k.Key, v => v.Value), exception);
    }

    public abstract void Log();

    public abstract void Log(LogLevel logLevel, string message, Exception? exception = null);

    public abstract void Log(LogLevel logLevel, IDictionary<string, object> state, Exception? exception = null);

    public virtual bool IsEnabled(LogLevel logLevel)
    {
        return true;
    }

    public abstract IDisposable BeginScope<TState>(TState state);
}

Now usage:

MockLogger<Service> logger = Substitute.For<MockLogger<Service>>();
logger.IsEnabled(LogLevel.Error).Returns(true);

string originalFormat = "Service returned error with code: '{statusCode}' and reason: '{reason}'";
var statusCode = HttpStatusCode.BadRequest;
string reason = "The reason...";

string message = $"Service returned error with code: '{(int)statusCode}' and reason: '{reason}'";

// Assert
logger.Received(1).Log(
            LogLevel.Error,
            Arg.Is<IDictionary<string, object>>(
                dict =>
                    dict.Any(kv => kv.Key == "{OriginalFormat}" && (string)kv.Value == originalFormat) &&
                    dict.Any(kv => kv.Key == "statusCode" && (int)kv.Value == (int)statusCode) &&
                    dict.Any(kv => kv.Key == "reason" && (string)kv.Value == reason)));

logger.Received(1).Log(LogLevel.Error, message);
logger.Received(1).Log();

It allows testing log parameters separately.

Upvotes: 4

Justin Lessard
Justin Lessard

Reputation: 11941

Looks like the accepted answer does not work in .NET Core 3 or .NET 5.

Here is the workaround found in the github issue

Create a new MockLogger class

public abstract class MockLogger : ILogger
{
    void ILogger.Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter) => 
        Log(logLevel, formatter(state, exception));

    public abstract void Log(LogLevel logLevel, string message);

    public virtual bool IsEnabled(LogLevel logLevel) => true;

    public abstract IDisposable BeginScope<TState>(TState state);
}

Replace your mocked logger with the new mock logger

// Old 
// var logger = Substitute.For<ILogger>();
// New
var logger = Substitute.For<MockLogger>();

Use the new logger to check calls

logger.Received().Log(LogLevel.Error, Arg.Is<string>(s => s.Contains("some log message")));

To use with a generic ILogger<T>, simply change the class to

public abstract class MockLogger<T> : ILogger<T>

Upvotes: 23

Valerii
Valerii

Reputation: 2317

LogError is not a ILogger method, so when you try to check that this method was called with certain parameters NSubstitute tries to handle it somehow(I do not know how exactly) and fails.

The code of LogError extension method is:

public static void LogError(this ILogger logger, string message, params object[] args)
{
  if (logger == null)
    throw new ArgumentNullException("logger");
  logger.Log<object>(LogLevel.Error, (EventId) 0, (object) new FormattedLogValues(message, args), (Exception) null, LoggerExtensions._messageFormatter);
}

So you have to check that Log method was called.

I simplified your example a bit. I think idea should be clear.

public partial class MainWindow : Window
{
    public MainWindow()
    {
        InitializeComponent();

        var logger = Substitute.For<ILogger>();
        try
        {
            Create(logger);
        }
        catch
        {
            logger.CheckErrorMessage("My Message");
        }
    }

    public string Create(ILogger logger)
    {
        try
        {
            throw new Exception("My Message");
        }
        catch (Exception e)
        {
            logger?.LogError(e.Message);
            throw new Exception("An error occurred while attempting to create a user.", e);
        }
    }
}

public static class TestExtensions
{
    public static void CheckErrorMessage(this ILogger logger, string message)
    {
        logger.Received().Log(
            LogLevel.Error,
            Arg.Any<EventId>(),
            Arg.Is<object>(o => o.ToString() == message),
            null,
            Arg.Any<Func<object, Exception, string>>());
    }
}

Upvotes: 32

Related Questions