ASP.Net Core Web API Capturing HTTP Requests for Logging

Question

I'm having difficulty capturing HTTP requests for logging purposes in ASP.NET Core Web API. I was able to find an example here

http://dotnetliberty.com/index.php/2016/01/07/logging-asp-net-5-requests-using-middleware/

which has helped. It's basically a logging class that gets added to the HTTP request pipeline using the middleware functionality. The problem is that the class method only gets invoked on application start up. I can't get it to be invoked on any of my get or post http requests. The get or post http requests are working because I can debug and the responses are ok which I tried using Fiddler and http client within a console application.

Here is my logging class

using Microsoft.AspNetCore.Http; 
using Microsoft.Extensions.Logging; 
using System; 
using System.Collections.Generic; 
using System.Diagnostics; 
using System.Linq; 
using System.Threading.Tasks; 


namespace CoreWebAPI.Models 
{ 
public class RequestLoggingMiddleware 
{ 
    private readonly RequestDelegate _next; 
    private readonly ILogger<RequestLoggingMiddleware> _logger; 


    public RequestLoggingMiddleware(RequestDelegate next, ILogger<RequestLoggingMiddleware> logger) 
    { 
        _next = next; 
        _logger = logger; 
    } 


    public async Task Invoke(HttpContext context) 
    { 
        var startTime = DateTime.UtcNow; 


        var watch = Stopwatch.StartNew(); 
        await _next.Invoke(context); 
        watch.Stop(); 


        var logTemplate = @" 
Client IP: {clientIP} 
Request path: {requestPath} 
Request content type: {requestContentType} 
Request content length: {requestContentLength} 
Start time: {startTime} 
Duration: {duration}"; 


        _logger.LogInformation(logTemplate, 
            context.Connection.RemoteIpAddress.ToString(), 
            context.Request.Path, 
            context.Request.ContentType, 
            context.Request.ContentLength, 
            startTime, 
            watch.ElapsedMilliseconds); 
    } 
} 
} 

And here is my Startup.Configure method in my Startup.cs class

    public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory) 
    { 
        loggerFactory.AddConsole(Configuration.GetSection("Logging")); 
        loggerFactory.AddDebug(); 




        app.UseApplicationInsightsRequestTelemetry(); 


        app.UseApplicationInsightsExceptionTelemetry(); 


        app.UseMvc(); 
        app.UseCors(builder => builder.AllowAnyOrigin()); 


        app.UseMiddleware<RequestLoggingMiddleware>(); 

    }

The last line is where I piggy back onto the HTTP requests using app.UseMiddleware. I think this should work but if anyone has a clue why it doesn't or an alternative that'd be great. Please let me know if you I should provide additional information.

Answer 1

The middleware are invoked in sort of a pipeline, in the order they are registered, and they all decide whether they should invoke the next one or not (see your own logging middleware: await _next.Invoke(context);).

When a requests comes in that is handled by the Mvc framework, it will not be passed down to the next middleware.

To get logging on all requests you need to put the registration of the logging before any middleware that terminates the pipeline, such as Mvc.

Answer 2

This will work just fine.

public async Task Invoke(HttpContext context)
{
    var timer = new Stopwatch();
    timer.Start();
    await _next(context);

    //Need to stop the timer after the pipeline finish
    timer.Stop();
    _logger.LogDebug("The request took '{0}' ms", timerer.ElapsedMilliseconds);
}

in the Startup you need to add the Middleware at the begining of the pipeline

public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory) 
{ 
    loggerFactory.AddConsole(Configuration.GetSection("Logging")); 
    loggerFactory.AddDebug(); 

    app.UseMiddleware<RequestLoggingMiddleware>();

    // rest of the middlewares 
      ..................

    app.UseMvc(); 
}