Trying to understand MockSequence

Question

I'm currently writing an application and to test it's correct behaviour I need to verify that methods are called in a given order.

For my Unit Tests, I'm using xUnit and Moq

Now, why do I need to test the order in which calls are being made?

I'm developing a solution that executes tasks on different threads. As soon as a task is executed, I'm writing a message to a given logger, so by checking the order in which the calls to the logger are made I'm sure that my code was implemented correctly.

See here the code which I'm trying to use:

public class SchedulerFixture
{
    #region Constructors

    public SchedulerFixture()
    {
        LoggerMock = new Mock<ILogger>(MockBehavior.Strict);

        // Setup of other mocks removed for simplicity.
    }

    #endregion
}

public class SequentialTaskExecutorMock : SchedulerFixture
{
    [Fact]
    public void Should_WriteTheCorrectLogEntries_WhenTasksAreExecutedAndNotCancelled()
    {
        // Defines the task that needs to be executed.
        var task = new LongRunningServiceTaskImplementation();

        // Built a sequence in which logs should be created.
        var sequence = new MockSequence();

        LoggerMock.Setup(x => x.Information(It.IsAny<string>(), It.IsAny<string>())).Verifiable();

        LoggerMock.InSequence(sequence).Setup(x => x.Information("émqsdlfk", "smdlfksdmlfk")).Verifiable();
        LoggerMock.InSequence(sequence).Setup(x => x.Information(LoggingResources.LoggerTitle, LoggingResources.Logger_ServiceStopped)).Verifiable();
        LoggerMock.InSequence(sequence).Setup(x => x.Information(LoggingResources.LoggerTitle, LoggingResources.Logger_ServiceStarted)).Verifiable();
        LoggerMock.InSequence(sequence).Setup(x => x.Information(LoggingResources.LoggerTitle, string.Format(CultureInfo.InvariantCulture, LoggingResources.Logger_TaskCompleted, task.TaskName))).Verifiable();
        LoggerMock.InSequence(sequence).Setup(x => x.Information(LoggingResources.LoggerTitle, LoggingResources.Logger_ServiceStopped)).Verifiable();

        // Setup the mock required for the tests.
        TaskGathererMock.Setup(x => x.GetServiceTasks(LoggerMock.Object)).Returns(() =>
        {
            return new[] { task };
        });

        // Start the scheduler.
        Scheduler.Start(TaskGathererMock.Object, ConfigurationManagerMock.Object);

        // Wait for 5 seconds (this simulates running the service for 5 seconds).
        // Since our tasks execution time takes 4 seconds, all the assigned tasks should have been completed.
        Thread.Sleep(5000);

        // Stop the service. (We assume that all the tasks have been completed).
        Scheduler.Stop();

        LoggerMock.VerifyAll();
    }
}

So, the first step in my test is to setup the logs, then the test itself is executed (this causes calls to the logger) and at the end I'm verifying it.

However, the test does pass always.

It should fail in this case since the following call:

LoggerMock.InSequence(sequence).Setup(x => x.Information("émqsdlfk", "smdlfksdmlfk")).Verifiable();

Is not executed anywhere in my code.

Answer 1

While this sure feels like a bug in Moq (see first comment to the question, by Patrick Quirk), here is a rough idea to what you could do instead. This is sort of a "long comment".

Make a simple class like:

class SequenceTracker
{
    int? state;

    public void Next(int newState)
    {
        if (newState <= state)
            Assert.Fail("Bad ordering there! States should be increasing.");

        state = newState;
    }
}

Then use it like this (modified version of your own code):

public void Should_WriteTheCorrectLogEntries_WhenTasksAreExecutedAndNotCancelled()
{
    // Defines the task that needs to be executed.
    var task = new LongRunningServiceTaskImplementation();

    // USE THE CLASS I PROPOSE:
    var tracker = new SequenceTracker();


    //LoggerMock.Setup(x => x.Information(It.IsAny<string>(), It.IsAny<string>()))

    LoggerMock.Setup(x => x.Information("émqsdlfk", "smdlfksdmlfk"))
        .Callback(() => tracker.Next(10));
    LoggerMock.Setup(x => x.Information(LoggingResources.LoggerTitle, LoggingResources.Logger_ServiceStopped))
        .Callback(() => tracker.Next(20));
    LoggerMock.Setup(x => x.Information(LoggingResources.LoggerTitle, LoggingResources.Logger_ServiceStarted))
        .Callback(() => tracker.Next(30));
    LoggerMock.Setup(x => x.Information(LoggingResources.LoggerTitle, string.Format(CultureInfo.InvariantCulture, LoggingResources.Logger_TaskCompleted, task.TaskName)))
        .Callback(() => tracker.Next(40));
    LoggerMock.Setup(x => x.Information(LoggingResources.LoggerTitle, LoggingResources.Logger_ServiceStopped))
        .Callback(() => tracker.Next(50));

    // Setup the mock required for the tests.
    TaskGathererMock.Setup(x => x.GetServiceTasks(LoggerMock.Object)).Returns(() =>
    {
        return new[] { task };
    });

    // Start the scheduler.
    Scheduler.Start(TaskGathererMock.Object, ConfigurationManagerMock.Object);

    // Wait for 5 seconds (this simulates running the service for 5 seconds).
    // Since our tasks execution time takes 4 seconds, all the assigned tasks should have been completed.
    Thread.Sleep(5000);

    // Stop the service. (We assume that all the tasks have been completed).
    Scheduler.Stop();

    // THIS NOW WORKS BECAUSE WE ABANDONED THE 'MockSequence' APPROACH:
    LoggerMock.VerifyAll();
}

Of course this can be made more advanced if desired.