more logging, more readme, more refactoring

src/Ocelot/Authentication/Handler/AuthenticationHandler.cs

@@ -1,16 +1,14 @@
-using Microsoft.AspNetCore.Http;
-
-namespace Ocelot.Authentication.Handler
+namespace Ocelot.Authentication.Handler
 {
     public class AuthenticationHandler
     {
-        public AuthenticationHandler(string provider, RequestDelegate handler)
+        public AuthenticationHandler(string provider, IHandler handler)
         {
             Provider = provider;
             Handler = handler;
         }
 
         public string Provider { get; private set; }
-        public RequestDelegate Handler { get; private set; }
+        public IHandler Handler { get; private set; }
     }
 }

src/Ocelot/Authentication/Handler/Factory/AuthenticationHandlerFactory.cs

@@ -23,7 +23,8 @@ namespace Ocelot.Authentication.Handler.Factory
 
             if (!handler.IsError)
             {
-                return new OkResponse<AuthenticationHandler>(new AuthenticationHandler(authOptions.Provider, handler.Data));
+                return new OkResponse<AuthenticationHandler>(
+                    new AuthenticationHandler(authOptions.Provider, new RequestDelegateHandler(handler.Data)));
             }
 
             return new ErrorResponse<AuthenticationHandler>(new List<Error>

src/Ocelot/Authentication/Handler/IHandler.cs

@@ -0,0 +1,10 @@
+using System.Threading.Tasks;
+using Microsoft.AspNetCore.Http;
+
+namespace Ocelot.Authentication.Handler
+{
+    public interface IHandler
+    {
+        Task Handle(HttpContext context);
+    }
+}

src/Ocelot/Authentication/Handler/RequestDelegateHandler.cs

@@ -0,0 +1,20 @@
+using System.Threading.Tasks;
+using Microsoft.AspNetCore.Http;
+
+namespace Ocelot.Authentication.Handler
+{
+    public class RequestDelegateHandler : IHandler
+    {
+        private readonly RequestDelegate _requestDelegate;
+
+        public RequestDelegateHandler(RequestDelegate requestDelegate)
+        {
+            _requestDelegate = requestDelegate;
+        }
+
+        public async Task Handle(HttpContext context)
+        {
+            await _requestDelegate.Invoke(context);
+        }
+    }
+}

src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs

@@ -44,7 +44,7 @@ namespace Ocelot.Authentication.Middleware
                 {
                     _logger.LogDebug("calling authentication handler for ReRoute");
 
-                    await authenticationHandler.Data.Handler.Invoke(context);
+                    await authenticationHandler.Data.Handler.Handle(context);
                 }
                 else
                 {

src/Ocelot/Cache/Middleware/OutputCacheMiddleware.cs

@@ -57,7 +57,7 @@ namespace Ocelot.Cache.Middleware
 
             _logger.LogDebug("succesfully called next middleware");
 
-            if (PipelineError())
+            if (PipelineError)
             {
                 _logger.LogDebug("there was a pipeline error for {downstreamUrlKey}", downstreamUrlKey);
 

src/Ocelot/Claims/Middleware/ClaimsBuilderMiddleware.cs

@@ -1,6 +1,7 @@
 using System.Linq;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
 using Ocelot.Infrastructure.RequestData;
 using Ocelot.Logging;
 using Ocelot.Middleware;

src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs

@@ -1,5 +1,6 @@
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
 using Ocelot.DownstreamRouteFinder.Finder;
 using Ocelot.Infrastructure.RequestData;
 using Ocelot.Logging;

src/Ocelot/DownstreamUrlCreator/Middleware/DownstreamUrlCreatorMiddleware.cs

@@ -1,6 +1,6 @@
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
-using Ocelot.DownstreamRouteFinder;
+using Microsoft.Extensions.Logging;
 using Ocelot.DownstreamUrlCreator.UrlTemplateReplacer;
 using Ocelot.Infrastructure.RequestData;
 using Ocelot.Logging;

src/Ocelot/Errors/Middleware/ExceptionHandlerMiddleware.cs

@@ -25,10 +25,10 @@ namespace Ocelot.Errors.Middleware
         public async Task Invoke(HttpContext context)
         {
             try
-            {   
-                _logger.LogDebug("calling middleware");
+            {
+                _logger.LogDebug("ocelot pipeline started");
 
-                _requestScopedDataRepository.Add("RequestId", context.TraceIdentifier);
+                _logger.LogDebug("calling next middleware");
 
                 await _next.Invoke(context);
 
@@ -42,6 +42,8 @@ namespace Ocelot.Errors.Middleware
                 _logger.LogError(message, e);
                 await SetInternalServerErrorOnResponse(context);
             }
+
+            _logger.LogDebug("ocelot pipeline finished");
         }
 
         private static async Task SetInternalServerErrorOnResponse(HttpContext context)

src/Ocelot/Headers/Middleware/HttpRequestHeadersBuilderMiddleware.cs

@@ -1,7 +1,9 @@
 using System.Linq;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
 using Ocelot.Infrastructure.RequestData;
+using Ocelot.Logging;
 using Ocelot.Middleware;
 
 namespace Ocelot.Headers.Middleware
@@ -10,24 +12,45 @@ namespace Ocelot.Headers.Middleware
     {
         private readonly RequestDelegate _next;
         private readonly IAddHeadersToRequest _addHeadersToRequest;
+        private readonly IOcelotLogger _logger;
 
-        public HttpRequestHeadersBuilderMiddleware(RequestDelegate next, 
+        public HttpRequestHeadersBuilderMiddleware(RequestDelegate next,
+            IOcelotLoggerFactory loggerFactory,
             IRequestScopedDataRepository requestScopedDataRepository,
             IAddHeadersToRequest addHeadersToRequest) 
             : base(requestScopedDataRepository)
         {
             _next = next;
             _addHeadersToRequest = addHeadersToRequest;
+            _logger = loggerFactory.CreateLogger<HttpRequestHeadersBuilderMiddleware>();
         }
 
         public async Task Invoke(HttpContext context)
         {
+            _logger.LogDebug("started calling headers builder middleware");
+
             if (DownstreamRoute.ReRoute.ClaimsToHeaders.Any())
             {
-                _addHeadersToRequest.SetHeadersOnContext(DownstreamRoute.ReRoute.ClaimsToHeaders, context);
+                _logger.LogDebug("this route has instructions to convert claims to headers");
+
+                var response = _addHeadersToRequest.SetHeadersOnContext(DownstreamRoute.ReRoute.ClaimsToHeaders, context);
+
+                if (response.IsError)
+                {
+                    _logger.LogDebug("there was an error setting headers on context, setting pipeline error");
+
+                    SetPipelineError(response.Errors);
+                    return;
+                }
+
+                _logger.LogDebug("headers have been set on context");
             }
-            
+
+            _logger.LogDebug("calling next middleware");
+
             await _next.Invoke(context);
+
+            _logger.LogDebug("succesfully called next middleware");
         }
     }
 }

src/Ocelot/Logging/IOcelotLoggerFactory.cs

@@ -46,21 +46,24 @@ namespace Ocelot.Logging
 
         public void LogDebug(string message, params object[] args)
         {
-            _logger.LogDebug(GetMessageWithRequestId(message), args);
+            _logger.LogDebug(GetMessageWithOcelotRequestId(message), args);
         }
 
         public void LogError(string message, Exception exception)
         {
-            _logger.LogError(GetMessageWithRequestId(message), exception);
+            _logger.LogError(GetMessageWithOcelotRequestId(message), exception);
         }
 
-        private string GetMessageWithRequestId(string message)
+        private string GetMessageWithOcelotRequestId(string message)
         {
             var requestId = _scopedDataRepository.Get<string>("RequestId");
 
-            return requestId.IsError 
-                ? $"{message} : RequestId: Error" 
-                : $"{message} : RequestId: {requestId.Data}";
+            if (requestId != null && !requestId.IsError)
+            {
+                return $"{message} : OcelotRequestId - {requestId.Data}";
+                
+            }
+            return $"{message} : OcelotRequestId - not set";
         }
     }
 }

src/Ocelot/Middleware/OcelotMiddleware.cs

@@ -15,22 +15,22 @@ namespace Ocelot.Middleware
             _requestScopedDataRepository = requestScopedDataRepository;
         }
 
-        public void SetPipelineError(List<Error> errors)
+        public bool PipelineError
         {
-            _requestScopedDataRepository.Add("OcelotMiddlewareError", true);
-            _requestScopedDataRepository.Add("OcelotMiddlewareErrors", errors);
+            get
+            {
+                var response = _requestScopedDataRepository.Get<bool>("OcelotMiddlewareError");
+                return response.Data;
+            }
         }
 
-        public bool PipelineError()
+        public List<Error> PipelineErrors
         {
-            var response = _requestScopedDataRepository.Get<bool>("OcelotMiddlewareError");
-            return response.Data;
-        }
-
-        public List<Error> GetPipelineErrors()
-        {
-            var response = _requestScopedDataRepository.Get<List<Error>>("OcelotMiddlewareErrors");
-            return response.Data;
+            get
+            {
+                var response = _requestScopedDataRepository.Get<List<Error>>("OcelotMiddlewareErrors");
+                return response.Data;
+            }
         }
 
         public DownstreamRoute DownstreamRoute
@@ -87,7 +87,12 @@ namespace Ocelot.Middleware
         public void SetHttpResponseMessageThisRequest(HttpResponseMessage responseMessage)
         {
             _requestScopedDataRepository.Add("HttpResponseMessage", responseMessage);
+        }
 
+        public void SetPipelineError(List<Error> errors)
+        {
+            _requestScopedDataRepository.Add("OcelotMiddlewareError", true);
+            _requestScopedDataRepository.Add("OcelotMiddlewareErrors", errors);
         }
     }
 }

src/Ocelot/Middleware/OcelotMiddlewareExtensions.cs

@@ -47,7 +47,7 @@ namespace Ocelot.Middleware
             builder.UseIfNotNull(middlewareConfiguration.PreErrorResponderMiddleware);
 
             // This is registered first so it can catch any errors and issue an appropriate response
-            builder.UseHttpErrorResponderMiddleware();
+            builder.UseResponderMiddleware();
 
             // Then we get the downstream route information
             builder.UseDownstreamRouteFinderMiddleware();
@@ -108,7 +108,7 @@ namespace Ocelot.Middleware
             // Everything should now be ready to build or HttpRequest
             builder.UseHttpRequestBuilderMiddleware();
 
-            //We fire off the request and set the response on the context in this middleware
+            //We fire off the request and set the response on the scoped data repo
             builder.UseHttpRequesterMiddleware();
 
             return builder;

src/Ocelot/QueryStrings/Middleware/QueryStringBuilderMiddleware.cs

@@ -1,7 +1,9 @@
 using System.Linq;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
 using Ocelot.Infrastructure.RequestData;
+using Ocelot.Logging;
 using Ocelot.Middleware;
 
 namespace Ocelot.QueryStrings.Middleware
@@ -10,24 +12,43 @@ namespace Ocelot.QueryStrings.Middleware
     {
         private readonly RequestDelegate _next;
         private readonly IAddQueriesToRequest _addQueriesToRequest;
+        private readonly IOcelotLogger _logger;
 
-        public QueryStringBuilderMiddleware(RequestDelegate next, 
+        public QueryStringBuilderMiddleware(RequestDelegate next,
+            IOcelotLoggerFactory loggerFactory,
             IRequestScopedDataRepository requestScopedDataRepository,
             IAddQueriesToRequest addQueriesToRequest) 
             : base(requestScopedDataRepository)
         {
             _next = next;
             _addQueriesToRequest = addQueriesToRequest;
+            _logger = loggerFactory.CreateLogger<QueryStringBuilderMiddleware>();
         }
 
         public async Task Invoke(HttpContext context)
         {
+            _logger.LogDebug("started calling query string builder middleware");
+
             if (DownstreamRoute.ReRoute.ClaimsToQueries.Any())
             {
-                _addQueriesToRequest.SetQueriesOnContext(DownstreamRoute.ReRoute.ClaimsToQueries, context);
+                _logger.LogDebug("this route has instructions to convert claims to queries");
+
+                var response = _addQueriesToRequest.SetQueriesOnContext(DownstreamRoute.ReRoute.ClaimsToQueries, context);
+
+                if (response.IsError)
+                {
+                    _logger.LogDebug("there was an error setting queries on context, setting pipeline error");
+
+                    SetPipelineError(response.Errors);
+                    return;
+                }
             }
-            
+
+            _logger.LogDebug("calling next middleware");
+
             await _next.Invoke(context);
+
+            _logger.LogDebug("succesfully called next middleware");
         }
     }
 }

src/Ocelot/Request/Middleware/HttpRequestBuilderMiddleware.cs

@@ -1,6 +1,8 @@
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
 using Ocelot.Infrastructure.RequestData;
+using Ocelot.Logging;
 using Ocelot.Middleware;
 using Ocelot.Request.Builder;
 
@@ -10,18 +12,23 @@ namespace Ocelot.Request.Middleware
     {
         private readonly RequestDelegate _next;
         private readonly IRequestCreator _requestCreator;
+        private readonly IOcelotLogger _logger;
 
-        public HttpRequestBuilderMiddleware(RequestDelegate next, 
+        public HttpRequestBuilderMiddleware(RequestDelegate next,
+            IOcelotLoggerFactory loggerFactory,
             IRequestScopedDataRepository requestScopedDataRepository, 
             IRequestCreator requestCreator)
             :base(requestScopedDataRepository)
         {
             _next = next;
             _requestCreator = requestCreator;
+            _logger = loggerFactory.CreateLogger<HttpRequestBuilderMiddleware>();
         }
 
         public async Task Invoke(HttpContext context)
         {
+            _logger.LogDebug("started calling request builder middleware");
+
             var buildResult = await _requestCreator
                 .Build(context.Request.Method, DownstreamUrl, context.Request.Body,
                     context.Request.Headers, context.Request.Cookies, context.Request.QueryString,
@@ -29,13 +36,20 @@ namespace Ocelot.Request.Middleware
 
             if (buildResult.IsError)
             {
+                _logger.LogDebug("IRequestCreator returned an error, setting pipeline error");
+
                 SetPipelineError(buildResult.Errors);
                 return;
             }
+            _logger.LogDebug("setting upstream request");
 
             SetUpstreamRequestForThisRequest(buildResult.Data);
 
+            _logger.LogDebug("calling next middleware");
+
             await _next.Invoke(context);
+
+            _logger.LogDebug("succesfully called next middleware");
         }
     }
 }

src/Ocelot/RequestId/Middleware/RequestIdMiddleware.cs

@@ -3,6 +3,7 @@ using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
 using Microsoft.Extensions.Primitives;
 using Ocelot.Infrastructure.RequestData;
+using Ocelot.Logging;
 using Ocelot.Middleware;
 
 namespace Ocelot.RequestId.Middleware
@@ -10,22 +11,35 @@ namespace Ocelot.RequestId.Middleware
     public class RequestIdMiddleware : OcelotMiddleware
     {
         private readonly RequestDelegate _next;
+        private readonly IOcelotLogger _logger;
+        private readonly IRequestScopedDataRepository _requestScopedDataRepository;
 
-        public RequestIdMiddleware(RequestDelegate next, 
+        public RequestIdMiddleware(RequestDelegate next,
+            IOcelotLoggerFactory loggerFactory,
             IRequestScopedDataRepository requestScopedDataRepository)
             :base(requestScopedDataRepository)
         {
             _next = next;
+            _logger = loggerFactory.CreateLogger<RequestIdMiddleware>();
+            _requestScopedDataRepository = requestScopedDataRepository;
         }
 
         public async Task Invoke(HttpContext context)
-        {
-            SetTraceIdentifier(context);
+        {         
+            _logger.LogDebug("started calling request id middleware");
+
+            SetOcelotRequestId(context);
+
+            _logger.LogDebug("set request id");
+
+            _logger.LogDebug("calling next middleware");
 
             await _next.Invoke(context);
+            
+            _logger.LogDebug("succesfully called next middleware");
         }
 
-        private void SetTraceIdentifier(HttpContext context)
+        private void SetOcelotRequestId(HttpContext context)
         {
             var key = DefaultRequestIdKey.Value;
 
@@ -38,6 +52,8 @@ namespace Ocelot.RequestId.Middleware
 
             if (context.Request.Headers.TryGetValue(key, out requestId))
             {
+                _requestScopedDataRepository.Add("RequestId", requestId.First());
+
                 context.TraceIdentifier = requestId;
             }
         }

src/Ocelot/Requester/Middleware/HttpRequesterMiddleware.cs

@@ -1,6 +1,8 @@
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
 using Ocelot.Infrastructure.RequestData;
+using Ocelot.Logging;
 using Ocelot.Middleware;
 
 namespace Ocelot.Requester.Middleware
@@ -9,27 +11,38 @@ namespace Ocelot.Requester.Middleware
     {
         private readonly RequestDelegate _next;
         private readonly IHttpRequester _requester;
+        private readonly IOcelotLogger _logger;
 
-        public HttpRequesterMiddleware(RequestDelegate next, 
+        public HttpRequesterMiddleware(RequestDelegate next,
+            IOcelotLoggerFactory loggerFactory,
             IHttpRequester requester, 
             IRequestScopedDataRepository requestScopedDataRepository)
             :base(requestScopedDataRepository)
         {
             _next = next;
             _requester = requester;
+            _logger = loggerFactory.CreateLogger<HttpRequesterMiddleware>();
         }
 
         public async Task Invoke(HttpContext context)
         {
+            _logger.LogDebug("started calling requester middleware");
+
             var response = await _requester.GetResponse(Request);
 
             if (response.IsError)
             {
+                _logger.LogDebug("IHttpRequester returned an error, setting pipeline error");
+
                 SetPipelineError(response.Errors);
                 return;
             }
 
+            _logger.LogDebug("setting http response message");
+
             SetHttpResponseMessageThisRequest(response.Data);
+
+            _logger.LogDebug("returning to calling middleware");
         }
     }
 }

src/Ocelot/Responder/Middleware/HttpResponderMiddlewareExtensions.cs

@@ -1,12 +0,0 @@
-using Microsoft.AspNetCore.Builder;
-
-namespace Ocelot.Responder.Middleware
-{
-    public static class HttpResponderMiddlewareExtensions
-    {
-        public static IApplicationBuilder UseHttpErrorResponderMiddleware(this IApplicationBuilder builder)
-        {
-            return builder.UseMiddleware<HttpErrorResponderMiddleware>();
-        }
-    }
-}

src/Ocelot/Responder/Middleware/ResponderMiddleware.cs

@@ -1,20 +1,24 @@
 using System.Collections.Generic;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
 using Ocelot.Errors;
 using Ocelot.Infrastructure.RequestData;
+using Ocelot.Logging;
 using Ocelot.Middleware;
 
 namespace Ocelot.Responder.Middleware
 {
-    public class HttpErrorResponderMiddleware : OcelotMiddleware
+    public class ResponderMiddleware : OcelotMiddleware
     {
         private readonly RequestDelegate _next;
         private readonly IHttpResponder _responder;
         private readonly IErrorsToHttpStatusCodeMapper _codeMapper;
+        private readonly IOcelotLogger _logger;
 
-        public HttpErrorResponderMiddleware(RequestDelegate next, 
+        public ResponderMiddleware(RequestDelegate next, 
             IHttpResponder responder,
+            IOcelotLoggerFactory loggerFactory,
             IRequestScopedDataRepository requestScopedDataRepository, 
             IErrorsToHttpStatusCodeMapper codeMapper)
             :base(requestScopedDataRepository)
@@ -22,24 +26,38 @@ namespace Ocelot.Responder.Middleware
             _next = next;
             _responder = responder;
             _codeMapper = codeMapper;
+            _logger = loggerFactory.CreateLogger<ResponderMiddleware>();
+
         }
 
         public async Task Invoke(HttpContext context)
         {
+            _logger.LogDebug("started error responder middleware");
+
             await _next.Invoke(context);
 
-            if (PipelineError())
+            _logger.LogDebug("calling next middleware");
+
+            if (PipelineError)
             {
-                var errors = GetPipelineErrors();
+                _logger.LogDebug("there is a pipeline error, getting errors");
+
+                var errors = PipelineErrors;
+
+                _logger.LogDebug("received errors setting error response");
 
                 await SetErrorResponse(context, errors);
             }
             else
             {
+                _logger.LogDebug("no pipeline error, setting response");
+
                 var setResponse = await _responder.SetResponseOnHttpContext(context, HttpResponseMessage);
 
                 if (setResponse.IsError)
                 {
+                    _logger.LogDebug("error setting response, returning error to client");
+
                     await SetErrorResponse(context, setResponse.Errors);
                 }
             }

src/Ocelot/Responder/Middleware/ResponderMiddlewareExtensions.cs

@@ -0,0 +1,12 @@
+using Microsoft.AspNetCore.Builder;
+
+namespace Ocelot.Responder.Middleware
+{
+    public static class ResponderMiddlewareExtensions
+    {
+        public static IApplicationBuilder UseResponderMiddleware(this IApplicationBuilder builder)
+        {
+            return builder.UseMiddleware<ResponderMiddleware>();
+        }
+    }
+}