Introduction

I’m a huge fan of “Clean” or “Hexagonal” architecture when writing applications. The reasons for this warrant their own blog post which I’ll get round to soon hopefully. But on a recent project for a client I came across a nice way to get transactional logging almost for free within the whole application, and I was delighted with how well it worked out.

Mediatr

There are a number of libraries available to help with implementing Hexagonal architecture, and in particular Command Dispatchers and Command Processors, Mediatr and Paramore Brighter are two that I know of, although I’m sure there are more out there.

I haven’t used Brighter myself but have listened to Ian Cooper talk about it many times. It was listening to these videos that made the architecture finally click for me. Both libraries solve the same problem, how to implement a port, but with Mediatr being smaller in scope I personally prefer it.

The idea behind Mediatr is to give you a separation between layers of your application, the end result being code that is loosely coupled and highly adaptable to change. It does this by giving you a some key interfaces IRequest<T> and IRequestHandler<T>. Create a class that implements IRequest<T> with any arguments you need, where T is the return type, then create an IRequestHandler<T> which will lean on your domain code to satisfy the request and return a result. Wire it all up following the examples given at the Mediatr github page https://github.com/jbogard/MediatR and you’re almost done. Bring in an IMediatr to your controller via dependency injection (also wired up following the examples from github) and you can pass it the request object and get the result back. If done correctly, the only interface your controllers rely on should be the IMediatr which marshalls requests from the web adapter into your application.

I follow CQRS(ish) when writing applications so split out command and query requests into their own namespaces and don’t pollute their concerns together, following a convention of commands finishing with Command e.g. SaveCustomerCommand and queries ending with Query so GetCustomerOrdersQuery. Likewise the handlers for these end in Handler so SaveCustomerHandler and GetCustomerOrdersHandler in this example. The “ish” part for CQRS is that occasionally it is handy to have a response from a Command and so they have return types sometimes, generally the ID of something was just created.

I don’t want to go into too much detail around Mediatr as there is lots of documentation online for more detail but it’s good to have a small overview.

The Magic Logging Part

So once you have your application working nicely you can add in the logging. I personally like to use Serilog for logging as it’s easy to use, supports lots of “Sinks” or outputs like SQL server, a rolling file on disk, the console, and many more. Again there isn’t much need to go into detail around this as there’s plenty of documentation online around it, and you can use your own preference in your own code.

The magic part is leaning on pre/post processing pipelines from Mediatr and a little bit of reflection.

So I have the code below and that’s essentially it! One class and I get every transaction through the system logged with a username attached for “who dunnit” reporting. The ILog is just an abstraction over Serilog, the RequestContext is a transient dependency fleshed out in an IRequestPreProcessor<T> which will be run at the start of each request through Mediatr and pulls a value from the IHttpContextAccessor to get the username from a JWT token on the request.

Because I follow the convention of naming Commands with the Command suffix I can just inspect the type of the request, if it contains “Command” then I can log the contents of the request. No matter what the request is I get the full state of the command, it’s type, and contents all for free thanks to Mediatr and Serilog. You could dial this back to only log certain things, record metrics for queries, absolutely anything. The RequestContext being available in pre/post processors would make this trivial to implement and to turn on/off via a toggle or config.

    public class PostCommandLogging<TRequest, TResponse> : IRequestPostProcessor<TRequest, TResponse>
    {
        private readonly ILog _log;
        private readonly RequestContext _context;

        public PostCommandLogging(ILog log, RequestContext context)
        {
            _log = log;
            _context = context;
        }

        public Task Process(TRequest request, TResponse response, CancellationToken cancellationToken)
        {
            var name = request.GetType().Name;
            if (name.Contains("Command"))
            {
                _log.Command(name, request, _context.Username);
            }

            return Task.FromResult("");
        }
    }

Closing

I hope this has been useful to you in some way. The concept is a simple one and with a little imagination you can see how this approach can be used to log all kinds of useful information as it flows through your code. Combined with something like ElasticSearch you could get some really interesting metrics from your system.