From 9774580c4e540e05d6016b80f171e1e4ebe54e63 Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Tue, 14 Mar 2017 17:43:24 +0000 Subject: [PATCH] Change logging for various middleware As part #35 logging is being checked. This commit changes the first four middlewares within the pipeline to be more standardised. Also added an extension method to easily print out the errors from a list of errors. --- .../Middleware/AuthenticationMiddleware.cs | 56 +++++++++++-------- .../DownstreamRouteFinderMiddleware.cs | 13 +++-- .../Extensions/ErrorListExtensions.cs | 18 ++++++ .../Middleware/ClientRateLimitMiddleware.cs | 14 ++++- .../Middleware/RequestIdMiddleware.cs | 11 ++-- .../Responder/ErrorsToHttpStatusCodeMapper.cs | 5 ++ 6 files changed, 82 insertions(+), 35 deletions(-) create mode 100644 src/Ocelot/Infrastructure/Extensions/ErrorListExtensions.cs diff --git a/src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs b/src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs index 037deeee..da4af616 100644 --- a/src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs +++ b/src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs @@ -5,6 +5,7 @@ using Microsoft.AspNetCore.Http; using Ocelot.Authentication.Handler.Factory; using Ocelot.Configuration; using Ocelot.Errors; +using Ocelot.Infrastructure.Extensions; using Ocelot.Infrastructure.RequestData; using Ocelot.Logging; using Ocelot.Middleware; @@ -33,47 +34,57 @@ namespace Ocelot.Authentication.Middleware public async Task Invoke(HttpContext context) { - _logger.LogDebug("started authentication"); + _logger.LogTrace($"entered {MiddlwareName}"); if (IsAuthenticatedRoute(DownstreamRoute.ReRoute)) { + _logger.LogDebug($"{context.Request.Path} is an authenticated route. {MiddlwareName} checking if client is authenticated"); + var authenticationHandler = _authHandlerFactory.Get(_app, DownstreamRoute.ReRoute.AuthenticationOptions); - if (!authenticationHandler.IsError) - { - _logger.LogDebug("calling authentication handler for ReRoute"); - - await authenticationHandler.Data.Handler.Handle(context); - } - else - { - _logger.LogDebug("there was an error getting authentication handler for ReRoute"); - + if (authenticationHandler.IsError) + { + _logger.LogError($"Error getting authentication handler for {context.Request.Path}. {authenticationHandler.Errors.ToErrorString()}"); SetPipelineError(authenticationHandler.Errors); - } + return; + } + + await authenticationHandler.Data.Handler.Handle(context); + if (context.User.Identity.IsAuthenticated) { - _logger.LogDebug("the user was authenticated"); + _logger.LogDebug($"Client has been authenticated for {context.Request.Path}"); + _logger.LogTrace($"{MiddlwareName} invoking next middleware"); await _next.Invoke(context); - _logger.LogDebug("succesfully called next middleware"); + _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); + _logger.LogTrace($"completed {MiddlwareName}"); } else { - _logger.LogDebug("the user was not authenticated"); + var error = new List + { + new UnauthenticatedError( + $"Request for authenticated route {context.Request.Path} by {context.User.Identity.Name} was unauthenticated") + }; - SetPipelineError(new List { new UnauthenticatedError($"Request for authenticated route {context.Request.Path} by {context.User.Identity.Name} was unauthenticated") }); + _logger.LogError($"Client has NOT been authenticated for {context.Request.Path} and pipeline error set. {error.ToErrorString()}"); + SetPipelineError(error); + + _logger.LogTrace($"completed {MiddlwareName}"); + return; } } else - { - _logger.LogDebug("calling next middleware"); - - await _next.Invoke(context); - - _logger.LogDebug("succesfully called next middleware"); + { + _logger.LogTrace($"No authentication needed for {context.Request.Path}. Invoking next middleware from {MiddlwareName}"); + + await _next.Invoke(context); + + _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); + _logger.LogTrace($"completed {MiddlwareName}"); } } @@ -83,3 +94,4 @@ namespace Ocelot.Authentication.Middleware } } } + diff --git a/src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs b/src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs index 02e3e4f6..79ed899d 100644 --- a/src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs +++ b/src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs @@ -1,6 +1,9 @@ +using System.Linq; +using System.Security.Cryptography.X509Certificates; using System.Threading.Tasks; using Microsoft.AspNetCore.Http; using Ocelot.DownstreamRouteFinder.Finder; +using Ocelot.Infrastructure.Extensions; using Ocelot.Infrastructure.RequestData; using Ocelot.Logging; using Ocelot.Middleware; @@ -27,7 +30,7 @@ namespace Ocelot.DownstreamRouteFinder.Middleware public async Task Invoke(HttpContext context) { - _logger.LogDebug("started calling downstream route finder middleware"); + _logger.LogTrace($"entered {MiddlwareName}"); var upstreamUrlPath = context.Request.Path.ToString().SetLastCharacterAs('/'); @@ -37,7 +40,7 @@ namespace Ocelot.DownstreamRouteFinder.Middleware if (downstreamRoute.IsError) { - _logger.LogDebug("IDownstreamRouteFinder returned an error, setting pipeline error"); + _logger.LogError($"{MiddlwareName} setting pipeline errors. IDownstreamRouteFinder returned {downstreamRoute.Errors.ToErrorString()}"); SetPipelineError(downstreamRoute.Errors); return; @@ -47,12 +50,12 @@ namespace Ocelot.DownstreamRouteFinder.Middleware SetDownstreamRouteForThisRequest(downstreamRoute.Data); - _logger.LogDebug("calling next middleware"); + _logger.LogTrace($"invoking next middleware from {MiddlwareName}"); await _next.Invoke(context); - _logger.LogDebug("succesfully called next middleware"); - + _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); + _logger.LogTrace($"completed {MiddlwareName}"); } } } \ No newline at end of file diff --git a/src/Ocelot/Infrastructure/Extensions/ErrorListExtensions.cs b/src/Ocelot/Infrastructure/Extensions/ErrorListExtensions.cs new file mode 100644 index 00000000..9c06d607 --- /dev/null +++ b/src/Ocelot/Infrastructure/Extensions/ErrorListExtensions.cs @@ -0,0 +1,18 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using Microsoft.Extensions.Primitives; +using Ocelot.Errors; + +namespace Ocelot.Infrastructure.Extensions +{ + public static class ErrorListExtensions + { + public static string ToErrorString(this List errors) + { + var listOfErrorStrings = errors.Select(x => "Error Code: " + x.Code.ToString() + " Message: " + x.Message); + return string.Join(" ", listOfErrorStrings); + } + } +} diff --git a/src/Ocelot/RateLimit/Middleware/ClientRateLimitMiddleware.cs b/src/Ocelot/RateLimit/Middleware/ClientRateLimitMiddleware.cs index 1b3efee1..f9cb72b5 100644 --- a/src/Ocelot/RateLimit/Middleware/ClientRateLimitMiddleware.cs +++ b/src/Ocelot/RateLimit/Middleware/ClientRateLimitMiddleware.cs @@ -30,12 +30,14 @@ namespace Ocelot.RateLimit.Middleware } public async Task Invoke(HttpContext context) - { - _logger.LogDebug("started calling RateLimit middleware"); + { + _logger.LogTrace($"entered {MiddlwareName}"); + var options = DownstreamRoute.ReRoute.RateLimitOptions; // check if rate limiting is enabled if (!DownstreamRoute.ReRoute.EnableEndpointRateLimiting) { + _logger.LogDebug($"EndpointRateLimiting is not enabled for {DownstreamRoute.ReRoute.DownstreamPathTemplate}. Invoking next middleware from {MiddlwareName}."); await _next.Invoke(context); return; } @@ -45,6 +47,7 @@ namespace Ocelot.RateLimit.Middleware // check white list if (IsWhitelisted(identity, options)) { + _logger.LogDebug($"{DownstreamRoute.ReRoute.DownstreamPathTemplate} is white listed from rate limiting. Invoking next middleware from {MiddlwareName}."); await _next.Invoke(context); return; } @@ -76,7 +79,12 @@ namespace Ocelot.RateLimit.Middleware context.Response.OnStarting(SetRateLimitHeaders, state: headers); } - await _next.Invoke(context); + _logger.LogTrace($"invoking next middleware from {MiddlwareName}"); + + await _next.Invoke(context); + + _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); + _logger.LogTrace($"completed {MiddlwareName}"); } public virtual ClientRequestIdentity SetIdentity(HttpContext httpContext, RateLimitOptions option) diff --git a/src/Ocelot/RequestId/Middleware/RequestIdMiddleware.cs b/src/Ocelot/RequestId/Middleware/RequestIdMiddleware.cs index 21667351..d6e493ae 100644 --- a/src/Ocelot/RequestId/Middleware/RequestIdMiddleware.cs +++ b/src/Ocelot/RequestId/Middleware/RequestIdMiddleware.cs @@ -26,17 +26,18 @@ namespace Ocelot.RequestId.Middleware public async Task Invoke(HttpContext context) { - _logger.LogDebug("started calling request id middleware"); + _logger.LogTrace($"entered {MiddlwareName}"); SetOcelotRequestId(context); - _logger.LogDebug("set request id"); + _logger.LogDebug("set requestId"); - _logger.LogDebug("calling next middleware"); + _logger.LogTrace($"invoking next middleware from {MiddlwareName}"); await _next.Invoke(context); - - _logger.LogDebug("succesfully called next middleware"); + + _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); + _logger.LogTrace($"completed {MiddlwareName}"); } private void SetOcelotRequestId(HttpContext context) diff --git a/src/Ocelot/Responder/ErrorsToHttpStatusCodeMapper.cs b/src/Ocelot/Responder/ErrorsToHttpStatusCodeMapper.cs index 45aeafd1..abba08b1 100644 --- a/src/Ocelot/Responder/ErrorsToHttpStatusCodeMapper.cs +++ b/src/Ocelot/Responder/ErrorsToHttpStatusCodeMapper.cs @@ -27,6 +27,11 @@ namespace Ocelot.Responder return new OkResponse(503); } + if (errors.Any(e => e.Code == OcelotErrorCode.UnableToFindDownstreamRouteError)) + { + return new OkResponse(404); + } + return new OkResponse(404); } }