How do we log authentication token requests in ASP.NET Web API

Question

We have an ASP.NET Web Api application which uses OAuth Bearer Tokens for authentication, for which we are trying to implement Request/Response logging.

Basically it works like this:
1. User sends request to "/authenticate" and receives an authentication token
2. User then uses this authentication token for requests to the exposed API methods

For logging requests to the exposed API methods, we use a DelegatingHandler which works perfectly fine.

However, requests made to "/authenticate" are not captured by the DelegatingHandler implementation.

Is there a different approach required for logging requests for tokens?

public abstract class MessageHandler : DelegatingHandler
{
    protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
    {
        var correlationId = Guid.NewGuid();

        var requestInfo = string.Format("{0} {1}", request.Method, request.RequestUri);

        var requestContent = await request.Content.ReadAsByteArrayAsync();

        var context = ((HttpContextBase)request.Properties["MS_HttpContext"]);

        await IncomingMessageAsync(correlationId, request.Method, request.RequestUri, request.Headers, requestContent, 
            context.Request.UserHostAddress, context.Request.IsAuthenticated, context.User.Identity.Name);

        var response = await base.SendAsync(request, cancellationToken);

        byte[] responseMessage;

        responseMessage = await response.Content.ReadAsByteArrayAsync();

        await OutgoingMessageAsync(correlationId, response.StatusCode, response.Headers, responseMessage);

        return response;
    }

    protected abstract Task IncomingMessageAsync(Guid correlationId, HttpMethod requestMethod, Uri requestUri, HttpRequestHeaders requestHeaders, byte[] messageContent, string ipAddress, bool isAuthenticated, string requestMadeByUserName);
    protected abstract Task OutgoingMessageAsync(Guid correlationId, HttpStatusCode statusCode, HttpResponseHeaders responseHeaders, byte[] messageContent);
}

EDIT w/ OAuth Code

[assembly: OwinStartup(typeof(MyApp.Infrastructure.IdentityConfig))]
namespace MyApp.Infrastructure
{
    public class IdentityConfig
    {
        public void Configuration(IAppBuilder app)
        {
            app.CreatePerOwinContext<ApplicationIdentityDbContext>(() => ApplicationIdentityDbContext.Create(ConfigurationDataProvider.MYDBCONNSTRING));
            app.CreatePerOwinContext<ApplicationUserManager>(ApplicationUserManager.Create);
            app.CreatePerOwinContext<ApplicationRoleManager>(ApplicationRoleManager.Create);

            app.UseOAuthBearerTokens(new OAuthAuthorizationServerOptions
            {
                 Provider = new ApplicationAuthProvider(),
                 AllowInsecureHttp = true,
                 TokenEndpointPath = new PathString("/Authenticate")
            });
        }
    }
}

Perhaps you can use [OnResponseSignIn](https://msdn.microsoft.com/en-us/library/microsoft.owin.security.cookies.cookieauthenticationprovider.onresponsesignin(v=vs.113).aspx)? — DavidG, Jun 13 '16 at 14:49
Thanks for the suggestion David. I'm not sure if this will work as we are using OAuthBearerTokens instead of cookies. — thiag0, Jun 15 '16 at 02:27
How is your OAuth middleware set up then, can you show that code? — DavidG, Jun 15 '16 at 07:29

MvdD · Accepted Answer · 2016-06-17T16:33:12.867

5

You are installing OWIN middleware to issue tokens before the WebAPI middleware.

 app.UseOAuthBearerTokens(new OAuthAuthorizationServerOptions
     {
         Provider = new ApplicationAuthProvider(),
         AllowInsecureHttp = true,
         TokenEndpointPath = new PathString("/Authenticate")
     });

The DelegatingHandler you try to use to log the request is part of the Web API middeware and is never reached because the token issuing middleware handles the request and does not call middleware further in the pipeline.

Instead of using DelegatingHandler, use the following middleware and install it before the token middleware.

public class RequestLoggerMiddleware
{
    private readonly Func<IDictionary<string, object>, Task> _next;
    private readonly ILogger _logger;

    public RequestLoggerMiddleware(
        Func<IDictionary<string, object>, Task> next, 
        ILogger logger)
    {
        _next = next;
        _logger = logger;
    }

    public Task Invoke(IDictionary<string, object> environment)
    {
        var context = new OwinContext(environment);

        _logger.Write($"{context.Request.Method} {context.Request.Uri.AbsoluteUri}");
        var result = _next.Invoke(environment);
        _logger.Write($"Status code: {context.Response.StatusCode}");

        return result;
    }
}

To install the middleware, just insert the statement: app.Use(typeof (RequestLoggerMiddleware)); before the app.UseOAuthBearerTokens statement in your Startup.cs.

edited Jun 17 '16 at 16:33

answered Jun 15 '16 at 21:50

MvdD

22,082
8
65
93

Makes sense. Can you point me to a resource showing how to register the "RequestLoggerMiddleware" before the OAuth middleware component? – thiag0 Jun 16 '16 at 13:37
@thiag0 Just insert the statement: `app.Use(typeof (RequestLoggerMiddleware));` before the `app.UseOAuthBearerTokens` statement. – MvdD Jun 16 '16 at 15:53
When using this approach, what is the proper way to read the request content, and wait for the response to be processed, so that can be logged as well? – thiag0 Jun 17 '16 at 14:37
@thiag0 I've updated my answer to also log the reponse code. HTH. – MvdD Jun 17 '16 at 16:33
Cool, thanks. Is there some special way that we need to read context.Request.Body and context.Response.Body? For example, in the DelegatingHandler if we access the buffer directly, it makes it unavailable for other handlers further in the chain, so we have to copy it to an internal buffer with HttpRequestMessage.Content.ReadAsByteArrayAsync(). Do we have to take the same approach in this scenario? – thiag0 Jun 17 '16 at 16:41
Yes, if you want to read the response body stream, you have to restore it for anything further down the pipeline. See this answer: http://stackoverflow.com/a/21805602/18044 – MvdD Jun 17 '16 at 16:49
When I add the RequestLoggerMiddleware class and the app.use line in the example to my similar Startup I get "RequestLoggerMiddleware' does not have a constructor taking 1 arguments" error – Ege Bayrak Feb 02 '18 at 08:16
Additional dependencies are specified after the type of the middleware, like this: `app.Use(typeof(RequestLoggerMiddleware), new Logger());`. – mhangan Dec 14 '18 at 12:30

How do we log authentication token requests in ASP.NET Web API

1 Answers1