Tag Archives: Marten

My integration testing challenges this week

EDIT 3/12: All these tests are fixed, and it wasn’t as bad as I’d thought it was going to be, but the extra logging and faster change code/run test under debugger cycle definitely helped.

This was meant to be a short post, or at least an easy to write post on my part, but it spilled out from integration testing and into some Storyteller mechanics, semi-advanced xUnit.Net usage, ASP.Net Core logging integration, and even a tepid defense of compositional architectures wrapped around an IoC container.

I’ve been working feverishly the past couple of months to push Jasper to a 1.0 release. As (knock on wood) the last big epic, I’ve been working on a large overhaul and redesign of the message persistence behind Jasper’s durable messaging. The existing code was fairly well covered by integration tests, so I felt confident that I could make the large scale changes and use the big bang integration tests to ensure the intended functionality still worked as designed.

I assume that y’all can guess how this has turned out. After a week of code changes and fixing any and all unit test and intermediate integration test failures, I got to the point where I was ready to run the big bang integration tests and, get this, they didn’t pass on the first attempt! I know, shocking right? Moreover, the tests involve all kinds of background processing and even multiple logical applications (think ASP.Net Core IWebHost objects) being started up and shut down during the tests, so it wasn’t exactly easy to spot the source of my test failures.

I thought it’d be worth talking about how I first stopped and invested in improving my test harness to make it faster to launch the test harness and to capture a lot more information about what’s going on in all the multithreading/asynchronous madness going on but…

First, an aside on Debugger Hell

You probably want to have some kind of debugger in your IDE of choice. You also want to be reasonably good using that tool, know how to use its features, and conversant in its supported keyboard shortcuts. You also want to try really hard to avoid needing to use your debugger too often because that’s just not an efficient way to get things done. Many folks in the early days of Agile development, including me, described debugger usage as a code or testing “smell.” And while “smell” is mostly used today as a pejorative to put down something that you just don’t like, it was originally just meant as a warning you should pay more attention to in your code or approach.

In the case of debugger usage, it might be telling you that your testing approach needs to be more fine grained or that you are missing crucial test coverage at lower levels. In my case, I’ll be looking for places where I’m missing smaller tests on elements of the bigger system and fill in those gaps before getting too worked up trying to solve the big integration test failures.

Storyteller Test Harness

For these big integration tests, I’m using Storyteller as my testing tool (think Cucumber,  but much more optimized for integration testing as opposed to being cute). With Storyteller, I’ve created a specification language that lets me script out message failover scenarios like the one shown below (which is currently failing as I write this):

JasperFailoverSpec

In the specification above, I’m starting and stopping Jasper applications to prove out Jasper’s ability to fail over and recover pending work from one running node to another using its Marten message persistence option. At runtime, Jasper has a background “durability agent” constantly running that is polling the database to determine if there is any unclaimed work to do or known application nodes are down (using advisory locks through Postgresql if anybody would ever be interested in a blog post about just that). Hopefully that’s enough description just to know that this isn’t particularly an easy scenario to test or code.

In my initial attempts to diagnose the failing Storyteller tests I bumped into a couple problems and sources of friction:

  1. It was slow and awkward mechanically to get the tests running under the debugger (that’s been a long standing problem with Storyteller and I’m finally happy with the approach shown later in this post)
  2. I could tell quickly that exceptions were being thrown and logged in the background processing, but I wasn’t capturing that log output in any kind of usable way

Since I’m pretty sure that the tests weren’t going to get resolved quickly and that I’d probably want to write even more of these damn tests, I believed that I first needed to invest in better visibility into what was happening inside the code and a much quicker way to cycle into the debugger. To that end, I took a little detour and worked on some Storyteller improvements that I’ve been meaning to do for quite a while.

Incorporating Logging into Storyteller Results

Jasper uses the ASP.Net Core logging abstractions for its own internal logging, but I didn’t have anything configured except for Debug and Console tracing to capture the logs being generated at runtime. Even with the console output, what I really wanted was all the log information correlated with both the individual test execution and which receiver or sender application the logging was from.

Fortunately, Storyteller has an extensibility model to capture custom logging and instrumentation directly into its test results. It turned out to be very simple to whip together an adapter for ASP.Net Core logging that captured the logging information in a way that can be exposed by Storyteller.

You can see the results in the image below. The table below is just showing all the logging messages received by ILogger within the “Receiver1” application during one test execution. The yellow row is an exception that was logged during the execution that I might not have been able to sense otherwise.

AspNetLoggingInStoryteller

For the implementation, ASP.Net Core exposes the ILoggerProvider service such that you can happily plug in as many logging strategies as you want to an application in a combinatorial way. On the Storyteller side of things, you have the Report interface that let’s you plug in custom logging that can expose HTML output into Storyteller’s results.

Implementing that crudely came out as a single class that implements both adapter interface (here’s a gist of the whole thing):

public class StorytellerAspNetCoreLogger : Report, ILoggerProvider

The actual logging just tracks all the calls to ILogger.Log() as little model objects in memory:

public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
{
    var logRecord = new LogRecord
    {
        Category = _categoryName,
        Level = logLevel.ToString(),
        Message = formatter(state, exception),
        ExceptionText = exception?.ToString()
    };

    // Just keep all the log records in an in memory list
    _parent.Records.Add(logRecord);
}

Fortunately enough, in the Storyteller Fixture code for the test harness I bootstrap the receiver and sender applications per test execution, so it’s really easy to just add the new StorytellerAspNetCoreLogger to both the Jasper applications and the Storyteller test engine:

var registry = new ReceiverApp();
registry.Services.AddSingleton<IMessageLogger>(_messageLogger);

var logger = new StorytellerAspNetCoreLogger(key);

// Tell Storyteller about the new logger so that it'll be
// rendered as part of Storyteller's results
Context.Reporting.Log(logger);

// This is bootstrapping a Jasper application through the 
// normal ASP.Net Core IWebHostBuilder
return JasperHost
    .CreateDefaultBuilder()
    .ConfigureLogging(x =>
    {
        x.SetMinimumLevel(LogLevel.Debug);
        x.AddDebug();
        x.AddConsole();
        
        // Add the logger to the new Jasper app
        // being built up
        x.AddProvider(logger);
    })

    .UseJasper(registry)
    .StartJasper();

And voila, the logging information is now part of the test results in a useful way so I can see a lot more information about what’s happening during the test execution.

It sucks that my code is throwing exceptions instead of just working, but at least I can see what the hell is going wrong now.

Get the debugger going quickly

To be honest, the friction of getting Storyteller tests running under a debugger has always been a drawback to Storyteller — especially compared to how fast that workflow is with tools like xUnit.Net that integrate seamlessly into your IDE. You’ve always been able to just attach your debugger to the running Storyteller process, but I’ve always found that to be clumsy and slow — especially when you’re trying to quickly cycle between attempted fixes and re-running the tests.

I made some attempts in Storyteller 5 to improve the situation (after we gave up on building a dotnet test adapter because that model is bonkers), but that still takes some set up time to make it work and even I have to always run to the documentation to remember how to do it. Sometime this weekend the solution for a quick xUnit.Net execution wrapper around Storyteller popped into my head and it honestly took about 15 minutes flat to get things working so that I could kick off individual Storyteller specifications from xUnit.Net as shown below:

StorytellerWithinXUnit

Maybe that’s not super exciting, but the end result is that I can rerun a specification after making changes with or without debugging with nothing but a simple keyboard shortcut in the IDE. That’s a dramatically faster feedback cycle than what I had to begin with.

Implementation wise, I just took advantage of xUnit.Net’s [MemberData] feature for parameterized tests and Storyteller’s StorytellerRunner class that was built to allow users to run specifications from their own code. After adding a new xUnit.Net test project and referencing the original Storyteller specification project named “StorytellerSpecs, ” I added the code file shown below in its entirety::

// This only exists as a hook to dispose the static
// StorytellerRunner that is hosting the underlying
// system under test at the end of all the spec
// executions
public class StorytellerFixture : IDisposable
{
    public void Dispose()
    {
        Runner.SpecRunner.Dispose();
    }
}

public class Runner : IClassFixture<StorytellerFixture>
{
    internal static readonly StoryTeller.StorytellerRunner SpecRunner;

    static Runner()
    {
        // I'll admit this is ugly, but this establishes where the specification
        // files live in the real StorytellerSpecs project
        var directory = AppContext.BaseDirectory
            .ParentDirectory()
            .ParentDirectory()
            .ParentDirectory()
            .ParentDirectory()
            .AppendPath("StorytellerSpecs")
            .AppendPath("Specs");

        SpecRunner = new StoryTeller.StorytellerRunner(new SpecSystem(), directory);
    }

    // Discover all the known Storyteller specifications
    public static IEnumerable<object[]> GetFiles()
    {
        var specifications = SpecRunner.Hierarchy.Specifications.GetAll();
        return specifications.Select(x => new object[] {x.path}).ToArray();
    }

    // Use a touch of xUnit.Net magic to be able to kick off and
    // run any Storyteller specification through xUnit
    [Theory]
    [MemberData(nameof(GetFiles))]
    public void run_specification(string path)
    {
        var results = SpecRunner.Run(path);
        if (!results.Counts.WasSuccessful())
        {
            SpecRunner.OpenResultsInBrowser();
            throw new Exception(results.Counts.ToString());
        }
    }
}

And that’s that. Something I’ve wanted to have for ages and failed to build, done in 15 minutes because I happened to remember something similar we’d done at work and realized how absurdly easy xUnit.Net made this effort.

Summary

  • Sometimes it’s worthwhile to take a step back from trying to solve a problem through debugging and invest in better instrumentation or write some automation scripts to make the debugging cycles faster rather than just trying to force your way through the solution
  • Inspiration happens at random times
  • Listen to that niggling voice in your head sometimes that’s telling you that you should be doing things differently in your code or tests
  • Using a modular architecture that’s composed by an IoC container the way that ASP.net Core does can sometimes be advantageous in integration testing scenarios. Case in point is how easy it was for me to toss in an all new logging provider that captured the log information directly into the test results for easier test failure resolution

And when I get around to it, these little Storyteller improvements will end up in Storyteller itself.

Advertisements

My OSS Plans for 2019

I wrote a similar post last year on My OSS Plans for 2018, and it wasn’t too far off what actually happened. I did switch jobs last May, and until recently, that dramatically slowed down my rate of OSS contributions and my ambition level for OSS work. I still enjoy building things, I’m in what’s supposed to be a mostly non-coding role now (but I absolutely still do), and working on OSS projects is just a good way to try to keep my technical skills up. So here we go:

Marten — I’m admittedly not super active with Marten these days as it’s a full fledged community driven project now. There has been a pile up of Linq related issues lately and the issue backlog is getting a bit big, so it really wouldn’t hurt for me to be more active. I happen to love Stephen King’s Dark Tower novels (don’t bother with the movie), but he used to complain that they were hard for him to get into the right head space to write more about Roland and his Ka-tet. That’s basically how I feel about the Linq provider in Marten, but it’s over due for some serious love.

Lamar (was BlueMilk) — Users are reporting some occasional memory usage problems that I think point to issues in Roslyn itself, but in the meantime I’ve got some workarounds in mind to at least alleviate the issue (maybe, hopefully, knock on wood). The one and only big feature idea for this year I have in mind is to finally do the “auto-factory” feature that I hope will knock out a series of user requests for more dynamic behavior.

Alba — I took some time at CodeMash this year and did a pretty substantial 3.0 release that repositioned Alba as a productivity helper on top of TestServer to hopefully eliminate a whole lot of compatibility issues with ASP.Net Core. I don’t know that I have any other plans for Alba this year, but it’s the one tool I work on that I actually get to use at work, so there might be some usability improvements over time.

Storyteller — I’d really love to sink into a pretty big rewrite of the user interface and some incremental — but perfectly backward compatible — improvements to the engine. After a couple years of mostly doing integration work, I suddenly have some UI centric projects ahead of me and I could definitely use some refresher on building web UIs. More on this in a later post.

Jasper — I think I’m finally on track for a 1.0 release in the next couple months, but I’m a little unsure if I want to wait for ASP.Net Core 3.0 or not. After that, it’s mostly going to be trying to build some community around Jasper. Most of my side project time and effort the past three years has been toward Jasper, I have conceptual notes on its architecture that go back at least 5 years, and counting its predecessor project FubuMVC, this has been a 10 year effort for me. Honestly, I think I’m going to finish the push to 1.0 just to feel some sense of completion.

Oakton — I feel like it’s basically done

StructureMap — I answer questions here and there, but otherwise it’s finished/abandoned

FubuMVC — Dead, but little bits and pieces of it live on in Oakton, Alba, and Jasper

 

Marten 3.4: Full text search

Marten 3.4 was release this week with bug fixes, some performance improvements (by using ImTools internally in place of ConcurrentDictionary), and one giant new feature to support full text searching using Postgresql v10’s new full text searching features. Congratulations to the core Marten team (Babu Annamalai, Oscar Dudycz,  and Joona-Pekka Kokko) for all their hard work on this release.

Taken from the Marten docs, here’s some of the usage:

Postgres contains built in Text Search functions. They enable the possibility to do more sophisticated searching through text fields. Marten gives possibility to define Full Text Indexes and perform queries on them. Currently three types of full Text Search functions are supported:

  • regular Search (to_tsquery)
var posts = session.Query<BlogPost>()
    .Where(x => x.Search("somefilter"))
    .ToList();
  • plain text Search (plainto_tsquery)
var posts = session.Query<BlogPost>()
    .Where(x => x.PlainTextSearch("somefilter"))
    .ToList();
  • phrase Search (phraseto_tsquery)
var posts = session.Query<BlogPost>()
    .Where(x => x.PhraseSearch("somefilter"))
    .ToList();

All types of Text Searches can be combined with other Linq queries

var posts = session.Query<BlogPost>()
    .Where(x => x.Category == "LifeStyle")
    .Where(x => x.PhraseSearch("somefilter"))
    .ToList();

They allow also to specify language (regConfig) of the text search query (by default english is being used)

var posts = session.Query<BlogPost>()
    .Where(x => x.PhraseSearch("somefilter", "italian"))
    .ToList();

See also, Full Text indexes for information on setting up indexing on documents.

Marten 3.0 is Released and Introducing the new Core Team

banner

Hey, look at that, Marten 3.0 is live on Nuget. It didn’t turn out to be a huge release, but we needed to accommodate the Npgsql 4.* dependency and I felt like that was a breaking change, so here we go. You can see the full list of bug fixes and changes in this list. Besides the usage of Npgsql 4, our biggest change was making the default schema object creation mode to this:

AutoCreateSchemaObjects = AutoCreate.CreateOrUpdate

Meaning that Marten even in its default mode will not drop any existing tables, even in development mode. You can still opt into the full “sure, I’ll blow away a table and start over if it’s incompatible” mode, but we felt like this option was safer after a few user problems were reported with the previous rules. See Schema Migrations and Patches for more information.

More exciting for me because I think it’s a mark of Marten becoming a real grownup open source project, Marten now has an official core contributor team who can review and approve pull requests:

All of them have been contributing to Marten for quite awhile and have been absolutely invaluable to supporting our community. Please join me in welcoming them all to the new team and looking forward to wherever Marten goes next.

 

Marten 2.10.0 and 3.0.0-alpha-2 are released.

The latest set of changes to Marten were just published as Marten 2.10.0 and Marten 3.0.0-alpha-2, with the only real difference being that the 3.0 alpha supports Npgsql 4. The complete list of changes is here. The latest docs have also been published. I counted 15 users total (not including me) in this release as either contributors or just folks who took the time to write up an actionable bug report (and don’t minimize the importance of that because it helps a ton). Thank you to all the Marten contributors and all the folks who answer questions in the Gitter room.

Do note that I quietly and unilaterally exercised my rights as the project’s benevolent dictator to finally remove Marten’s targeting for Netstandard1.* as it was annoying the crap out of me and I didn’t think many folks would care. As of 2.10.0, Marten targets net46 and netstandard2.0.

I hope that more serious work on the 3.0 release starts up again soon, but we’ll see.

Planning the Next Couple Marten Releases

I think we’ve got things lined up for a Marten 2.9 release in the next week with these highlights:

  • Fixes for netcoreapp2.1. A user found some issues with the Linq support so here we go.
  • The upgrade to Npgsql 4.0
  • Eliminating Netstandard 1.3 support. Marten will continue to target .Net 4.6 & Netstandard 2.0, and we’ll be running tests for net46, netcoreapp2.0, and netcoreapp2.1.
  • Some improvements on exception messages in the event store support
  • Upgrades to Newtonsoft.Json — but if the performance isn’t better than the baseline, I’ll leave it where it is

Brainstorming What’s Next

I’ve been admittedly putting  most of my OSS energy into other projects (Jasper/Lamar) for the past year, but the Marten community has been happily proceeding anyway. One of my goals for OSS work this year is to get the Marten issue list count (bugs, questions, and feature ideas) under 25 and keep it there so it’s only a single page in the GitHub website.

We’ve got a big backlog of issues and feature requests. For a potential Marten 2.9, I’d like to suggest:

That’s all for the document store, so now let’s talk about the event sourcing. I don’t have a huge amount of ideas because I don’t get to use it on real projects (yet), but here’s what I think just from responding to user problems:

  • The async daemon is up for some love, and I think I’ve learned some things from Jasper work that will be beneficial back in Marten. First, I think we can finally get a model where Marten itself can handle distributing the ownership of the projections between multiple application nodes so you can more easily deploy the async daemon. After a tip from one of my new colleagues at Calavista, I also want to pursue using “tombstone” events as placeholders on event capture failures to make the async daemon potentially quite a bit more efficient at runtime.
  • I think this would be an add on, but I have an idea for an alternative to ViewProjection that would let you write your projection as just methods on a class that take in any combination of the actual event, the IDocumentSession, the containing EventStream, or Event<T> metadata, then use Lamar to do its thing to generate the actual adapter to Marten’s projection model. I think this could end up being more efficient than ViewProjection is now at runtime, and certainly lead to cleaner code by eliminating the nested lambdas.
  • Event Store partitioning?
  • Event Store metadata extensions?

EDIT 6/8/2018: We had some discussions about this list on Gitter and I definitely forgot some big things here:

  • The async daemon and projections in general needs to be multi-tenancy friendly
  • Other users are interested in the multi-tenancy via database per tenant that got cut from 2.0 at the last minute

Any thoughts about any of this? Other requests? Comments are open, or head to Gitter to join the conversation about Marten.

 

Marten 3.0 with Sql Server Support????

I want to hold the line that there won’t be any kind of huge Marten 3.0 until there’s enough improvements to the JSON support in Sql Server vNext to justify an effort to finally make Marten database engine neutral. I’m also hoping that Marten 3.0 could completely switch all the Linq support to using queries based on SQL/Json too. See this blog post for why Marten does not yet support Sql Server.

Jasper’s “Outbox” Pattern Support

Jasper supports the “outbox pattern,”  a way to achieve consistency between the outgoing messages that you send out as part of a logical unit of work without having to resort to two phase, distributed transactions between your application’s backing database and whatever queueing technology you might be using. Why do you care? Because consistency is good, and distributed transactions suck, that’s why.

Before you read this, and especially if you’re a coworker freaking out because you think I’m trying to force you to use Postgresql, Jasper is not directly coupled to Postgresql and we will shortly add similar support to what’s shown here for Sql Server message persistence with Dapper and possibly Entity Framework.

Let’s say you have an ASP.Net Core MVC controller action like this in a system that is using Marten for document persistence:

public async Task<IActionResult> CreateItem(
    [FromBody] CreateItemCommand command,
    [FromServices] IDocumentStore martenStore,
    [FromServices] IMessageContext context)
{
    var item = createItem(command);

    using (var session = martenStore.LightweightSession())
    {
        session.Store(item);
        await session.SaveChangesAsync();
    }
    
    var outgoing = new ItemCreated{Id = item.Id};
    
    await context.Send(outgoing);

    return Ok();
}

It’s all contrived, but it’s a relatively common pattern. The HTTP action:

  1. Receives a CreateItemCommand message from the client
  2. Creates a new Item document and persists that with a Marten document session
  3. Broadcasts an ItemCreated event to any known subscribers through Jasper’s IMessageContext service. For the sake of the example, let’s say that under the covers Jasper is publishing the message through RabbitMQ (because I just happened to push Jasper’s RabbitMQ support today).

Let’s say that in this case we need both the document persistence and the message being sent out to either succeed together or both fail together to keep your system and any downstream subscribers consistent. Now, let’s think about all the ways things can go wrong:

  1. If we keep the code the way that it is, what if the transaction succeeds, but the call to context.Send() fails, so we’re inconsistent
  2. If we sent the message before we persisted the document, but the call to session.SaveChangesAsync() failed, we’re inconsistent
  3. The system magically fails and shuts down in between the document getting saved and the outgoing message being completely enqueued — and that’s not that crazy if the system handles a lot of messages

We’ve got a couple options. We can try to use a distributed transaction between the underlying RabbitMQ queue and the Postgresql database, but those can be problematic and are definitely not super performant. We could also use some kind of compensating transaction to reestablish consistency, but that’s just more code to write.

Instead, let’s use Jasper’s support for the “outbox” pattern with Marten:

public async Task<IActionResult> CreateItem(
    [FromBody] CreateItemCommand command,
    [FromServices] IDocumentStore martenStore,
    [FromServices] IMessageContext context)
{
    var item = createItem(command);
    
    using (var session = martenStore.LightweightSession())
    {
        // Directs the message context to hold onto
        // outgoing messages, and persist them 
        // as part of the given Marten document
        // session when it is committed
        await context.EnlistInTransaction(session);
        
        var outgoing = new ItemCreated{Id = item.Id};
        await context.Send(outgoing);
        
        session.Store(item);
        
        await session.SaveChangesAsync();
    }

    return Ok();
}

The key things to know here are:

  • The outgoing messages are persisted in the same Postgresql database as the Item document with a native database transaction.
  • The outgoing messages are not sent to RabbitMQ until the underlying database transaction in the call to session.SaveChangesAsync() succeeds
  • For the sake of performance, the message persistence goes up to Postgresql with all the document operations in one network round trip to the database for just a wee bit of performance optimization.

For more context, here’s a sequence diagram explaining how it works under the covers using Marten’s IDocumentSessionListener:

Handling a Message w_ Unit of Work Middleware (1)

So now, let’s talk about all the things that can go wrong and how the outbox usage makes it better:

  • The transaction fails. No messages will be sent out, so there’s no inconsistency.
  • The transaction succeeds, but the RabbitMQ broker is unreachable. It’s still okay. Jasper has the outgoing messages persisted, and the durable messaging support will continue to retry the outgoing messages when the broker is available again.
  • The transaction succeeds, but the application process is killed before the outgoing message is completely sent to RabbitMQ. Same as the bullet point above.

 

Outbox Pattern inside of Message Handlers

The outbox usage within a message handler for the same CreateItemCommand in its most explicit form might look like this:

public static async Task Handle(
    CreateItemCommand command, 
    IDocumentStore store, 
    IMessageContext context)
{
    var item = createItem(command);


    using (var session = store.LightweightSession())
    {
        await context.EnlistInTransaction(session);

        var outgoing = new ItemCreated{Id = item.Id};
        await context.Send(outgoing);

        session.Store(item);

        await session.SaveChangesAsync();
    }
}

Hopefully, that’s not terrible, but we can drastically simplify this code if you don’t mind some degree of “magic” using Jasper’s cascading message support and Marten transaction middleware:

[MartenTransaction]
public static ItemCreated Handle(
    CreateItemCommand command,
    IDocumentSession session)
{
    var item = createItem(command);

    session.Store(item);
    return new ItemCreated{Id = item.Id};
}

The usage of the [MartenTransaction] attribute directs Jasper to apply a transaction against the IDocumentSession usage and automatically enlists the IMessageContext for the message in that session. The outgoing ItemCreated message returned from the action is sent out through the same IMessageContext object.