adrianiftode/moq.ilogger

Easy verify ILogger Moq mocks

moq.ilogger's Issues

Moq.VerifyLogUnexpectedException

When running unit tests to verify logger is called as expected, Moq.ILogger threw this exception:

Moq.VerifyLogUnexpectedException : Moq.ILogger found an unexpected exception.
----> System.ArgumentNullException : Value cannot be null. (Parameter 'body')

Stack Trace:

    VerifyLogExtensions.Verify[T](Mock`1 loggerMock, Expression`1 expression, Nullable`1 times, Func`1 timesFunc, String failMessage)
    VerifyLogExtensions.VerifyLog(Mock`1 loggerMock, Expression`1 expression, Func`1 times)
    <>c__DisplayClass22_0.<ExampleAsync_HallOfFameInducteesNotEmpty_NoDuplicateIds_ValidatorIsValidTrue_RetrieveBOExecuteSuccessful_NewEntryAlreadyInSameCategory_ErrorSet>b__1() line 250
    Assert.Multiple(TestDelegate testDelegate)
    BusinessLogic.ExampleAsync_HallOfFameInducteesNotEmpty_NoDuplicateIds_ValidatorIsValidTrue_RetrieveBOExecuteSuccessful_NewEntryAlreadyInSameCategory_ErrorSet() line 248
    GenericAdapter`1.GetResult()
    AsyncToSyncAdapter.Await(Func`1 invoke)
    TestMethodCommand.RunTestMethod(TestExecutionContext context)
    TestMethodCommand.Execute(TestExecutionContext context)
    <>c__DisplayClass1_0.<Execute>b__0()
    DelegatingTestCommand.RunTestMethodInThreadAbortSafeZone(TestExecutionContext context, Action action)
    --ArgumentNullException
    ContractUtils.RequiresNotNull(Object value, String paramName, Int32 index)
    ExpressionUtils.RequiresCanRead(Expression expression, String paramName, Int32 idx)
    Expression.ValidateLambdaArgs(Type delegateType, Expression& body, ReadOnlyCollection`1 parameters, String paramName)
    Expression.Lambda[TDelegate](Expression body, String name, Boolean tailCall, IEnumerable`1 parameters)
    Expression.Lambda[TDelegate](Expression body, Boolean tailCall, IEnumerable`1 parameters)
    VerifyLogExpressionArgs.From(Expression expression)
    VerifyLogExpression.From(Expression expression)
    VerifyLogExtensions.Verify[T](Mock`1 loggerMock, Expression`1 expression, Nullable`1 times, Func`1 timesFunc, String failMessage)

Code:

public async Task ExampleAsync(IEnumerable<Models.HallOfFame> hallOfFameInductees, CancellationToken cancellationToken = default)
{
    var currentHallOfFamers = (await RetrieveBO.ExecuteAsync(cancellationToken)).ToList();

    var alreadyInducted = (from current in currentHallOfFamers
                            from inductee in hallOfFameInductees
                            where current.BowlerId == inductee.BowlerId
                            where AlreadyInducted(inductee, current)
                            select inductee).ToList();

    if (alreadyInducted.Count > 0)
    {
        Logger.LogError("Bowler(s) {alreadyInducted} already inducted to hall of fame", alreadyInducted);
        ErrorDetails.Add(new Models.ErrorDetail("Invalid Addition: Bowler already inducted"));

        return;
    }

    DataLayer.Execute(hallOfFameInductees);

    await DataAccess.CommitAsync(LocalTransaction, cancellationToken);
}

private static bool AlreadyInducted(Models.HallOfFame inductee, Models.HallOfFame current)
    => current.Category == Models.HallOfFameTypes.Combined || current.Category == inductee.Category;

Unit Test (hallOfFameInductees and hallOfFamers generated via Bogus, Fluent calls override properties set via Bogus):

[Test]
public async Task ExampleAsync_RetrieveBOExecuteSuccessful_NewEntryAlreadyInSameCategory_LoggerLogError_CalledCorrectly()
{
    var hallOfFameInductees = new[] { new Builders.Models.HallOfFame()
                                            .WithBowlerId(1)
                                            .WithYear(2000)
                                            .WithCategory(NEBA.Models.HallOfFameTypes.Performance)
                                            .Generate()};

    var hallOfFamers = new[] { new Builders.Models.HallOfFame()
                                            .WithBowlerId(1)
                                            .WithYear(1999)
                                            .WithCategory(NEBA.Models.HallOfFameTypes.Performance)
                                            .Generate()};

    _retrieveBO.Setup(retrieveBO => retrieveBO.ExecuteAsync(It.IsAny<CancellationToken>())).ReturnsAsync(hallOfFamers);

    await _businessLogic.ExampleAsync(hallOfFameInductees);

    _logger.VerifyLog(logger => logger.LogError("Bowler(s) {alreadyInducted} already inducted to hall of fame", hallOfFameInductees), Times.Once);
}

Models:

/// <summary>
/// 
/// </summary>
public sealed class HallOfFame
{
    /// <summary>
    /// 
    /// </summary>
    /// <value></value>
    public int Id { get; set; }

    /// <summary>
    /// 
    /// </summary>
    /// <value></value>
    public int BowlerId { get; set; }

    /// <summary>
    /// 
    /// </summary>
    /// <value></value>
    public int Year { get; set; }

    /// <summary>
    /// 
    /// </summary>
    /// <value></value>
    public HallOfFameTypes Category { get; set; }
}

/// <summary>
/// 
/// </summary>
public enum HallOfFameTypes
{
    /// <summary>
    /// 
    /// </summary>
    Performance = 100,

    /// <summary>
    /// 
    /// </summary>
    Service = 200,

    /// <summary>
    /// 
    /// </summary>
    Combined = 300,

    /// <summary>
    /// 
    /// </summary>
    Friend = 500
}

Wildcards are not working as expected

I just want to start off with a big thanks for this library, I had just started on creating a similar extension to test logging, when I stumbled upon this gem. Absolute life-saver.

I did however come across an issue and I'm not sure whether I'm using the extension wrong, or if it's an actual bug.

Here is my Mock-setup:
redisClient.Setup(x => x.SetAsync<BuyIntention>(It.IsAny<string>(), It.IsAny<BuyIntention>(), It.IsAny<CancellationToken>())).Throws(new Exception("Exception thrown"));

The code to log the exception
_logger.LogError(exception, $"Exception thrown trying to set ID {id} for Aggregate {aggregateId}");

In my test, I've added the following line to my Assert:
logger.VerifyLog(c => c.LogError(It.Is<Exception>(e => e.Message.Contains("Exception thrown")), $"*ID {id}*Aggregate {aggregateId}*"));

Which results in a Moq.VerifyLogException;
Expected invocation on the mock at least once, but was never performed:

Yet, when I remove the wildcards and check for the entire string:
logger.VerifyLog(c => c.LogError(It.Is<Exception>(e => e.Message.Contains("Exception thrown")), $"Exception thrown trying to set ID {id} for Aggregate {aggregateId}"));

The test is succesful.

This is an acceptable work-around for now, however, I would like to use the wildcards, since the specifications only state that we should at least log the ID and the AggregateID the code is trying to store in Redis.

Make it easier to verify logged exception ignoring StackTrace etc.

First and formost, this is a great library and works great, thank you!

Currently, when providing an exception to be verified, the verification also includes the StackTrace property of the exception and some other non relevant data that can never be matched when the exception is thrown internally from the SUT.

Please make it easier to verify exceptions by enabling skipping some irrelevant properties, such as StackTrace.

Thank you

Asserting log method called 0 times or never doesnt work

When trying to assert that the LogError method wasn't called using Times.Never or Times.Exactly(0), the result is always:

Expected invocation on the mock at least once, but was never performed

When I set the Times field to Times.Exactly(2) (for example), I get the result:

Expected invocation on the mock exactly 2 times, but was 0 times

My test is set up as follows:

    // sut
    public async Task<bool> Method() {
        var result = await _anotherService.DoSomething();  // this returns true/false

        if (!result) {
            _logger.LogError("An error");
        }

        return result;
    }


    // tests
    [Fact]
    public async void UseMethod_Success()
    {
      // Act
      var result = await _sut.Method();

      // Assert
      Assert.True(result);
      _logger.VerifyLog(x => x.LogError(It.IsAny<string>()), Times.Never); // Always expects it to be called once, even though `Times.Never` is set
    }

Ability to assert *not* logged message?

Looking to try and assert that a specific type/message was not logged - any capability for this?

e.g. if I run a method and expect everything to succeed, I want to ensure no LogWarning or LogErrors were sent during that execution.

failed test due to unexpected exception

Message: 
Moq.VerifyLogUnexpectedException : Moq.ILogger found an unexpected exception.

Please open an issue at https://github.com/adrianiftode/Moq.ILogger/issues/new, provide the exception details and a sample code if possible.
Below will follow the unexpected exception details.

----> System.FormatException : Index (zero based) must be greater than or equal to zero and less than the size of the argument list.

System.FormatException : Index (zero based) must be greater than or equal to zero and less than the size of the argument list.

Stack Trace: 
VerifyLogExtensions.Verify[T](Mock1 loggerMock, Expression1 expression, Nullable1 times, Func1 timesFunc, String failMessage)
VerifyLogExtensions.VerifyLog[T](Mock1 loggerMock, Expression1 expression)
SendKCITests.FailedToSendMessageToCommunicationManagement_SendReminderPriorDeletion_BadIdentityProvider() line 385
GenericAdapter1.GetResult() AsyncToSyncAdapter.Await(Func1 invoke)
TestMethodCommand.RunTestMethod(TestExecutionContext context)
TestMethodCommand.Execute(TestExecutionContext context)
<>c__DisplayClass1_0.b__0()
BeforeAndAfterTestCommand.RunTestMethodInThreadAbortSafeZone(TestExecutionContext context, Action action)
--FormatException
<6 more frames...>
<>c__DisplayClass7_01.<Is>b__0(Object argument, Type parameterType) line 172 MatchFactory.Matches(Object argument, Type parameterType) line 251 IMatcher.Matches(Object argument, Type parameterType) line 78 InvocationShape.IsMatch(Invocation invocation) line 132 WhereArrayIterator1.MoveNext()
Mock.GetMatchingInvocationCount(Mock mock, ImmutablePopOnlyStack1& parts, HashSet1 visitedInnerMocks, List1 invocationsToBeMarkedAsVerified) line 467 Mock.GetMatchingInvocationCount(Mock mock, LambdaExpression expression, List1& invocationsToBeMarkedAsVerified) line 439
Mock.Verify(Mock mock, LambdaExpression expression, Times times, String failMessage) line 323
Mock1.Verify(Expression1 expression, String failMessage) line 764
VerifyLogExtensions.Verify[T](Mock1 loggerMock, Expression1 expression, Nullable1 times, Func1 timesFunc, String failMessage)

sample code:
_loggerMock.VerifyLog(logger => logger.LogError(EventCodes.Cids.AutoDelete.Errors.AZFUNC_SENDKCI_SENDMESSAGE_EXCEPTION_FUNCTIONALITYNOTAVAILABLE,
"Send email reminder of user login before deletion not available for brand: {staleCidsAccount.Brand}, objectId: {staleCidsAccount.ObjectId} and correlationId: {correlationId}. Response : {response.Reason}",
_staleCidsAccountReminderToSendBT.Brand,
_staleCidsAccountReminderToSendBT.ObjectId,
_staleCidsAccountReminderToSendBT.CorrelationId
));

Unable to cast object of type 'System.Linq.Expressions.FieldExpression' to type 'System.Linq.Expressions.ConstantExpression'.

Moq.ILogger seems to be unable to verify with anything that isn't a constant expression. I am using version 1.1.3 and was able to reproduce the error with a simple testcase:

[Test]
public void ExpressionCastTest()
{
    var loggerMock = new Mock<ILogger<object>>();

    loggerMock.Object.LogInformation("test123");

    // works:
    loggerMock.VerifyLog(logger => logger.LogInformation(It.IsRegex(@"test\d+")));
    // fails:
    string expectedRegex = @"test\d+";
    loggerMock.VerifyLog(logger => logger.LogInformation(It.IsRegex(expectedRegex)));
}

with this stacktrace:

Moq.VerifyLogUnexpectedException : Moq.ILogger found an unexpected exception.

Please open an issue at https://github.com/adrianiftode/Moq.ILogger/issues/new, provide the exception details and a sample code if possible.
Bellow will follow the unexpected exception details.

  ----> System.InvalidCastException : Unable to cast object of type 'System.Linq.Expressions.FieldExpression' to type 'System.Linq.Expressions.ConstantExpression'.
   at Moq.VerifyLogExtensions.Verify[T](Mock`1 loggerMock, Expression`1 expression, Nullable`1 times, Func`1 timesFunc, String failMessage)
   at Moq.VerifyLogExtensions.VerifyLog[T](Mock`1 loggerMock, Expression`1 expression)
   at Tests.SomeTest.ExpressionCastTest() in D:\Tests\SomeTests.cs:line 76
--InvalidCastException
   at Moq.VerifyLogExtensions.CreateMessageExpression(VerifyLogExpression verifyLogExpression)
   at Moq.VerifyLogExtensions.CreateMoqVerifyExpressionFrom[T](VerifyLogExpression verifyLogExpression)
   at Moq.VerifyLogExtensions.Verify[T](Mock`1 loggerMock, Expression`1 expression, Nullable`1 times, Func`1 timesFunc, String failMessage)

Unable to cast object of type 'System.Linq.Expressions.MethodCallExpression1' to type 'System.Linq.Expressions.NewArrayExpression'.

I started adding Moq.ILogger to my test project this afternoon, and so far am very happy with it, thank you! However, while updating one of my tests, I encountered the following exception:

  Message: 
Moq.VerifyLogUnexpectedException : Moq.ILogger found an unexpected exception.

Please open an issue at https://github.com/adrianiftode/Moq.ILogger/issues/new, provide the exception details and a sample code if possible.
Bellow will follow the unexpected exception details.

---- System.InvalidCastException : Unable to cast object of type 'System.Linq.Expressions.MethodCallExpression1' to type 'System.Linq.Expressions.NewArrayExpression'.

  Stack Trace: 
VerifyLogExtensions.Verify[T](Mock`1 loggerMock, Expression`1 expression, Nullable`1 times, Func`1 timesFunc, String failMessage)
VerifyLogExtensions.VerifyLog[T](Mock`1 loggerMock, Expression`1 expression)
TestMyMethod.It_does_what_it_should(String someValue) line 67
--- End of stack trace from previous location ---
----- Inner Stack Trace -----
VerifyLogExpression.get_HasExpectedMessageArgs()
VerifyLogExtensions.CompareMessages(String expectedMessageFormat, VerifyLogExpression verifyLogExpression, Object actualMessageValues)
<>c__DisplayClass7_0`1.<Is>b__0(Object argument, Type parameterType) line 172
MatchFactory.Matches(Object argument, Type parameterType) line 251
IMatcher.Matches(Object argument, Type parameterType) line 78
InvocationShape.IsMatch(Invocation invocation) line 132
WhereArrayIterator`1.MoveNext()
Mock.GetMatchingInvocationCount(Mock mock, ImmutablePopOnlyStack`1& parts, HashSet`1 visitedInnerMocks, List`1 invocationsToBeMarkedAsVerified) line 467
Mock.GetMatchingInvocationCount(Mock mock, LambdaExpression expression, List`1& invocationsToBeMarkedAsVerified) line 439
Mock.Verify(Mock mock, LambdaExpression expression, Times times, String failMessage) line 323
Mock`1.Verify(Expression`1 expression, String failMessage) line 764
VerifyLogExtensions.Verify[T](Mock`1 loggerMock, Expression`1 expression, Nullable`1 times, Func`1 timesFunc, String failMessage)

My intention was to allow the test to still pass if the order in which the parameters passed to the log statement changed. For example, switching the logged message from ("The {Foo} received {Bar}", foo, bar) to ("{Bar} was sent to the {Foo}", bar, foo) should not cause the test to fail.

To that end, I was attempting to grab the object[] array of params and verify that it contained both Foo and Bar, without caring about order.

Here is a sample of the test that led to the above exception:

public async Task It_does_what_it_should (string someValue)
{
    Bar someInstance = new();

    await sut.MyMethodAsync(someValue, someInstance);

    mockLogger.VerifyLog(m => m.LogWarning(
        "*{Foo}*{@Bar}*",
        It.Is<object[]>(oo => oo.Contains(someValue) && oo.Contains(someInstance))
    ));
}

This seems to be the same general problem as in #3, but with different source and target types for the cast. I can resolve it by switching the constant string passed as the first argument to It.IsAny<string>(), or It.Is<string>(s => conditions(s)), which is fine for my use case, but wanted to report the unexpected exception to you as requested!

I'm using v1.1.9, with Moq 4.16.1. Please let me know if there are any additional details that would help, or if there's something in my approach that you'd expect the library to accomplish better in another way.

VerifyLog() doesn't work when message comes from Resource file.

This doesn't work.
Any idea ?

message : Could not deserialize input data for assessmentDetailId {Id}

In SUT

_logger.LogWarning(CoreResource.LOG_CouldNotDeserializeInputDataForAssessmentDetailId, assessmentDetail.Id);

In TEST

_mockLogger.VerifyLog(l => l.LogWarning(CoreResource.LOG_CouldNotDeserializeInputDataForAssessmentDetailId, It.IsAny<int>()), Times.Exactly(1));