OWIN middleware to correlate and log requests and responses?

Question

I'm writing a piece of custom OWIN middleware to log all http requests and their responses. I would like to "correlate" these with a trackingId. Here is the code:

public class PacketTrackingMiddleware
{
    private readonly AppFunc _next;

    public PacketTrackingMiddleware(AppFunc next)
    {
        _next = next;
    }

    public async Task Invoke(IDictionary<string, object> environment)
    {
        IOwinContext context = new OwinContext(environment);            
        var request = context.Request;
        var response = context.Response;

        //capture details about the caller identity

        var identity = (request.User != null && request.User.Identity.IsAuthenticated)
            ? request.User.Identity.Name
            : "(anonymous)";

        var apiPacket = new ApiPacket
        {
            CallerIdentity = identity
        };

        //buffer the request stream in order to intercept downstream reads
        var requestBuffer = new MemoryStream();
        request.Body = requestBuffer;

        //buffer the response stream in order to intercept downstream writes
        var responseStream = response.Body;
        var responseBuffer = new MemoryStream();
        response.Body = responseBuffer;

        //add the "Http-Tracking-Id" response header
        context.Response.OnSendingHeaders(state =>
        {
            var ctx = state as IOwinContext;
            if (ctx == null) return;
            var resp = ctx.Response;

            //adding the tracking id response header so that the user
            //of the API can correlate the call back to this entry
            resp.Headers.Add("http-tracking-id", new[] { apiPacket.TrackingId.ToString("d") });
        }, context);

        //invoke the next middleware in the pipeline
        await _next.Invoke(environment);

        //rewind the request and response buffers to record their content
        WriteRequestHeaders(request, apiPacket);
        requestBuffer.Seek(0, SeekOrigin.Begin);
        var requestReader = new StreamReader(requestBuffer);
        apiPacket.Request = await requestReader.ReadToEndAsync();

        WriteResponseHeaders(response, apiPacket);
        responseBuffer.Seek(0, SeekOrigin.Begin);
        var reader = new StreamReader(responseBuffer);
        apiPacket.Response = await reader.ReadToEndAsync();

        //write the apiPacket to the database
        //await database.InsterRecordAsync(apiPacket);
        System.Diagnostics.Debug.WriteLine("TrackingId: " + apiPacket.TrackingId);

        //make sure the response we buffered is flushed to the client
        responseBuffer.Seek(0, SeekOrigin.Begin);
        await responseBuffer.CopyToAsync(responseStream);
    }
    private static void WriteRequestHeaders(IOwinRequest request, ApiPacket packet)
    {
        packet.Verb = request.Method;
        packet.RequestUri = request.Uri;
        packet.RequestHeaders = request.Headers;
    }
    private static void WriteResponseHeaders(IOwinResponse response, ApiPacket packet)
    {
        packet.StatusCode = response.StatusCode;
        packet.ReasonPhrase = response.ReasonPhrase;
        packet.ResponseHeaders = response.Headers;
    }
}

I'm having trouble with adding the http-tracking-id to the response header (these lines here).

context.Response.OnSendingHeaders(state =>
{
    var ctx = state as IOwinContext;
    if (ctx == null) return;
    var resp = ctx.Response;

    resp.Headers.Add("http-tracking-id", new[] { apiPacket.TrackingId.ToString("d") });
}, context);

When adding the header I sometimes get this error:

HttpException was unhandled by user code.

Additional information: Server cannot append header after HTTP headers have been sent.

---

Edit 1: I am testing this by simply running the api, which opens chrome to my http://localhost:64051/ address. If I browse to any actual API (http://localhost:64051/api/Accounts/21067) for example, I don't receive the error. Should I somehow just be sending a 404 back when browsing to the root of the site?

Answer 1

I think it may be a simple fix. Please try:

var responseHeaders = (IDictionary<string, string[]>)environment["owin.ResponseHeaders"];
responseHeaders["http-tracking-id"] = new[] {apiPacket.TrackingId.ToString("d")};

But not in the context.Response.OnSendingHeaders. Just inline with the rest.