This post is Part 3 of a four-part series. You might want to read Part 1 and Part 2 first.

Let's continue our series on Middleware in .NET 6 by discussing the pipeline created by Middleware, and specifically why the order in which the middleware are added to the pipeline is very important.

You should know the order of things BEFORE this point. Photo by SELİM ARDA ERYILMAZ / Unsplash

The Sample Project

As with all of my code-focused posts, there's a demo project that demonstrates the ideas in this post over on GitHub. You can check it out here:

GitHub - exceptionnotfound/MiddlewareNET6Demo
Contribute to exceptionnotfound/MiddlewareNET6Demo development by creating an account on GitHub.

Order of Operations

Recall from Part 1 of this series that middleware forms a pipeline, and the middleware in that pipeline are executed in a certain order, an example of which is shown in this chart:

Requests flow through the middleware in order, and responses bubble up through the middleware in reverse order.

At this point in this series, we have defined two middleware classes: LoggingMiddleware for request/response logging, and SimpleResponseMiddleware which can short-circuit the pipeline to return a response.

In this post, we will start with only LoggingMiddleware in the pipeline:

//...Rest of Program.cs

app.UseLoggingMiddleware();

//...Rest of Program.cs

Adding a Delay

Let's imagine that we now have a new middleware class, called IntentionalDelayMiddleware, which looks like this:

namespace MiddlewareNET6Demo.Middleware
{
    public class IntentionalDelayMiddleware
    {
        private readonly RequestDelegate _next;

        public IntentionalDelayMiddleware(RequestDelegate next)
        {
            _next = next;
        }

        public async Task InvokeAsync(HttpContext context)
        {
            await Task.Delay(100);

            await _next(context);

            await Task.Delay(100);
        }
    }
}

As you can see, this middleware class waits 100ms both when processing the incoming request and when processing the outgoing response, for a total wait time of 200ms.

This is clearly not something we would want to do in the real world. For this post, we're not operating in the real world. Here, IntentionalDelayMiddleware represents some kind of undefined middleware that takes a predictable amount of time to execute.

We need to add an instance of IntentionalDelayMiddleware to the pipeline. The question is: do we add it before or after the LoggingMiddleware?

In this case, it most likely doesn't matter, since the two middleware classes don't interact and don't process the same thing. For this demo, let's add the IntentionalDelayMiddleware AFTER the LoggingMiddleware:

//...Rest of Program.cs

app.UseLoggingMiddleware();
app.UseIntentionalDelayMiddleware();

//...Rest of Program.cs

If we run the app now, we won't really notice a significant difference; 200ms is pretty quick.

Adding an Execution Time Middleware

But now there's a wrinkle (you knew there had to be). Imagine that we get a new requirement from our manager. S/he says that we need to log the execution time of every request to our system.

This is actually pretty straightforward to do with middleware; it uses the Stopwatch class provided by .NET and the LoggingService class we created in Part 2 of this series. Here's the middleware class, named TimeLoggingMiddleware:

using MiddlewareNET6Demo.Logging;
using System.Diagnostics;

namespace MiddlewareNET6Demo.Middleware
{
    public class TimeLoggingMiddleware
    {
        private readonly RequestDelegate _next;
        private readonly ILoggingService _logger;

        public TimeLoggingMiddleware(RequestDelegate next, 
                                     ILoggingService logger)
        {
            _next = next;
            _logger = logger;
        }

        public async Task InvokeAsync(HttpContext context)
        {
            Stopwatch watch = new Stopwatch();
            watch.Start();

            await _next(context);

            watch.Stop();
            _logger.Log(LogLevel.Information, "Time to execute: " + watch.ElapsedMilliseconds + " milliseconds.");
        }
    }
}

We need to add this to the pipeline. But again, that question remains: exactly where should we do so?

If we add the TimeLoggingMiddleware to the pipeline BEFORE the IntentionalDelayMiddleware, the delay caused by the latter will be included in the measurements taken by the former. If we add it AFTER, the delay will not be included, but is that an accurate measurement, especially if the delay in IntentionalDelayMiddleware changes?

In fact, let's expand our look at the pipeline:

//...Rest of Program.cs

app.UseHttpsRedirection();
app.UseStaticFiles();

//We can also use custom extensions to add middleware to the pipeline.
//Note that if this middleware causes any delay, that delay is
//NOT included in the time logs.
app.UseLoggingMiddleware();

//Here's the time logging middleware
app.UseTimeLoggingMiddleware();

//Here's the delay. At the moment, the delay is INCLUDED in the time logs.
app.UseIntentionalDelayMiddleware();

app.UseRouting();

app.UseAuthorization();

app.MapRazorPages();

app.Run();

Given this Program.cs file, where might be a more appropriate place to put the TimeLoggingMiddleware? That answer depends on several questions, such as:

  • Do the time logs need to include execution time for things like invalid authorizations? If so, the TimeLoggingMiddleware must be included BEFORE the call to app.UseAuthorization().
  • Routing a call takes a very small, but measurable, amount of time. Do we want to include that? If so, the TimeLoggingMiddleware must be included BEFORE the call to app.UseRouting().

Like most real-world problems, there's no clear answer here. Given no other direction, I personally would err on the side of NOT including the known delay in the measurement, but this is ultimately a decision that needs to be made by individual developers using their system's known quirks, rules, and guidelines.

The key part that you need to remember is that THIS:

//...Rest of Program.cs

app.UseIntentionalDelayMiddleware();
app.UseTimeLoggingMiddleware();

//...Rest of Program.cs

is potentially very different from THIS:

//...Rest of Program.cs

app.UseTimeLoggingMiddleware();
app.UseIntentionalDelayMiddleware();

//...Rest of Program.cs

This is one example of why the order of the middleware in the pipeline matters.

Coming Up Next!

In the fourth and final part of this series, we will demonstrate a few ways you can conditionally add or execute middleware in the pipeline. Stick around!

Happy Coding!