Wolverine’s Test Support Diagnostics

I’m working on fixing a reported bug with Wolverine today and its event forwarding from Marten feature. I can’t say that I yet know why this should-be-very-straightforward-and-looks-exactly-like-the-currently-passing-tests bug is happening, but it’s a good time to demonstrate Wolverine’s automated testing support and even how it can help you to understand test failures.

First off, and I’ll admit that there’s some missing context here, I’m setting up a system such that when this message handler is executed:

public record CreateShoppingList();

public static class CreateShoppingListHandler
{
    public static string Handle(CreateShoppingList _, IDocumentSession session)
    {
        var shoppingListId = CombGuidIdGeneration.NewGuid().ToString();
        session.Events.StartStream<ShoppingList>(shoppingListId, new ShoppingListCreated(shoppingListId));
        return shoppingListId;
    }
}

The configured Wolverine + Marten integration should be kicking in to publish the event appended in the handler above to a completely different handler shown below with the Marten IEvent wrapper so that you can use Marten event store metadata within the secondary, cascaded message:

public static class IntegrationHandler
{
    public static void Handle(IEvent<ShoppingListCreated> _)
    {
        // Don't need a body here, and I'll show why not
        // next
    }
}

Knowing those two things, here’s the test I wrote to reproduce the problem:

    [Fact]
    public async Task publish_ievent_of_t()
    {
        // The "Arrange"
        using var host = await Host.CreateDefaultBuilder()
            .UseWolverine(opts =>
            {
                opts.Policies.AutoApplyTransactions();

                opts.Services.AddMarten(m =>
                {
                    m.Connection(Servers.PostgresConnectionString);
                    m.DatabaseSchemaName = "forwarding";

                    m.Events.StreamIdentity = StreamIdentity.AsString;
                    m.Projections.LiveStreamAggregation<ShoppingList>();
                }).UseLightweightSessions()
                .IntegrateWithWolverine()
                .EventForwardingToWolverine();;
            }).StartAsync();
        
        // The "Act". This method is an extension method in Wolverine
        // specifically for facilitating integration testing that should
        // invoke the given message with Wolverine, then wait until all
        // additional "work" is complete
        var session = await host.InvokeMessageAndWaitAsync(new CreateShoppingList());

        // And finally, just assert that a single message of
        // type IEvent<ShoppingListCreated> was executed
        session.Executed.SingleMessage<IEvent<ShoppingListCreated>>()
            .ShouldNotBeNull();
    }

And now, when I run the test — which “helpfully” reproduces reported bug from earlier today — I get this output:

System.Exception: No messages of type Marten.Events.IEvent<MartenTests.Bugs.ShoppingListCreated> were received

System.Exception
No messages of type Marten.Events.IEvent<MartenTests.Bugs.ShoppingListCreated> were received
Activity detected:

----------------------------------------------------------------------------------------------------------------------
| Message Id                             | Message Type                          | Time (ms)   | Event               |
----------------------------------------------------------------------------------------------------------------------
| 018f82a9-166d-4c71-919e-3bcb04a93067   | MartenTests.Bugs.CreateShoppingList   |          873| ExecutionStarted    |
| 018f82a9-1726-47a6-b657-2a59d0a097cc   | System.String                         |         1057| NoRoutes            |
| 018f82a9-17b1-4078-9997-f6117fd25e5c   | EventShoppingListCreated              |         1242| Sent                |
| 018f82a9-166d-4c71-919e-3bcb04a93067   | MartenTests.Bugs.CreateShoppingList   |         1243| ExecutionFinished   |
| 018f82a9-17b1-4078-9997-f6117fd25e5c   | EventShoppingListCreated              |         1243| Received            |
| 018f82a9-17b1-4078-9997-f6117fd25e5c   | EventShoppingListCreated              |         1244| NoHandlers          |
----------------------------------------------------------------------------------------------------------------------

EDIT: If I’d read this more closely before, I would have noticed that the problem was somewhere different than the routing that I first suspected from a too casual read.

The textual table above is Wolverine telling me what it did do during the failed test. In this case, the output does tip me off that there’s some kind of issue with the internal message routing in Wolverine that should be applying some special rules for IEvent<T> wrappers, but was not in this case. While that work fixing the real bug continues for me, what I hope you get out of this is how Wolverine is trying to help you diagnose test failures by providing diagnostic information about what was actually happening internally during all the asynchronous processing. As a long veteran of test automation efforts, I will vociferously say that it’s important for test automation harnesses to be able to adequately explain the inevitable test failures. Like Wolverine helpfully does.

Now, back to work trying to actually fix the problem…