From 0ec7fc44ad31381be8bc2bb4949d9097cf4ae838 Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Mon, 13 Mar 2017 11:44:02 +0000 Subject: [PATCH 1/9] Change all ctor's to use IOcelotLoggerFactory As part of #35 we are we are standardising on using IOcelotLoggerFactory over the default ILogger for DI purposes. Following a sln search, the use of ILogger was only found in one place (FileOcelotConfigurationCreator) and it's corresponding tests. This commit changes them and ensures the unit tests still pass. --- .../Creator/FileOcelotConfigurationCreator.cs | 9 +++++---- .../Configuration/FileConfigurationCreatorTests.cs | 5 +++-- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/src/Ocelot/Configuration/Creator/FileOcelotConfigurationCreator.cs b/src/Ocelot/Configuration/Creator/FileOcelotConfigurationCreator.cs index 7147b40a..a2ebb709 100644 --- a/src/Ocelot/Configuration/Creator/FileOcelotConfigurationCreator.cs +++ b/src/Ocelot/Configuration/Creator/FileOcelotConfigurationCreator.cs @@ -9,6 +9,7 @@ using Ocelot.Configuration.File; using Ocelot.Configuration.Parser; using Ocelot.Configuration.Validator; using Ocelot.LoadBalancer.LoadBalancers; +using Ocelot.Logging; using Ocelot.Requester.QoS; using Ocelot.Responses; using Ocelot.Utilities; @@ -22,7 +23,7 @@ namespace Ocelot.Configuration.Creator { private readonly IOptions _options; private readonly IConfigurationValidator _configurationValidator; - private readonly ILogger _logger; + private readonly IOcelotLogger _logger; private readonly ILoadBalancerFactory _loadBalanceFactory; private readonly ILoadBalancerHouse _loadBalancerHouse; private readonly IQoSProviderFactory _qoSProviderFactory; @@ -38,8 +39,8 @@ namespace Ocelot.Configuration.Creator public FileOcelotConfigurationCreator( IOptions options, - IConfigurationValidator configurationValidator, - ILogger logger, + IConfigurationValidator configurationValidator, + IOcelotLoggerFactory loggerFactory, ILoadBalancerFactory loadBalancerFactory, ILoadBalancerHouse loadBalancerHouse, IQoSProviderFactory qoSProviderFactory, @@ -64,7 +65,7 @@ namespace Ocelot.Configuration.Creator _qosProviderHouse = qosProviderHouse; _options = options; _configurationValidator = configurationValidator; - _logger = logger; + _logger = loggerFactory.CreateLogger(); _claimsToThingCreator = claimsToThingCreator; _serviceProviderConfigCreator = serviceProviderConfigCreator; _qosOptionsCreator = qosOptionsCreator; diff --git a/test/Ocelot.UnitTests/Configuration/FileConfigurationCreatorTests.cs b/test/Ocelot.UnitTests/Configuration/FileConfigurationCreatorTests.cs index e3293a90..e6968d9d 100644 --- a/test/Ocelot.UnitTests/Configuration/FileConfigurationCreatorTests.cs +++ b/test/Ocelot.UnitTests/Configuration/FileConfigurationCreatorTests.cs @@ -8,6 +8,7 @@ using Ocelot.Configuration.Creator; using Ocelot.Configuration.File; using Ocelot.Configuration.Validator; using Ocelot.LoadBalancer.LoadBalancers; +using Ocelot.Logging; using Ocelot.Requester.QoS; using Ocelot.Responses; using Shouldly; @@ -22,7 +23,7 @@ namespace Ocelot.UnitTests.Configuration private readonly Mock _validator; private Response _config; private FileConfiguration _fileConfiguration; - private readonly Mock> _logger; + private readonly Mock _logger; private readonly FileOcelotConfigurationCreator _ocelotConfigurationCreator; private readonly Mock _loadBalancerFactory; private readonly Mock _loadBalancerHouse; @@ -44,7 +45,7 @@ namespace Ocelot.UnitTests.Configuration _qosProviderFactory = new Mock(); _qosProviderHouse = new Mock(); _qosProvider = new Mock(); - _logger = new Mock>(); + _logger = new Mock(); _validator = new Mock(); _fileConfig = new Mock>(); _loadBalancerFactory = new Mock(); From 3fb83077fb8e9f27d76a69c47003df35c7955103 Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Mon, 13 Mar 2017 17:23:09 +0000 Subject: [PATCH 2/9] Changed log messages to be a bit more descriptive --- .../Middleware/ExceptionHandlerMiddleware.cs | 3 + .../Middleware/ResponderMiddleware.cs | 144 +++++++++--------- 2 files changed, 75 insertions(+), 72 deletions(-) diff --git a/src/Ocelot/Errors/Middleware/ExceptionHandlerMiddleware.cs b/src/Ocelot/Errors/Middleware/ExceptionHandlerMiddleware.cs index ea5d2c84..dc36fd94 100644 --- a/src/Ocelot/Errors/Middleware/ExceptionHandlerMiddleware.cs +++ b/src/Ocelot/Errors/Middleware/ExceptionHandlerMiddleware.cs @@ -6,6 +6,9 @@ using Ocelot.Logging; namespace Ocelot.Errors.Middleware { + /// + /// Catches all unhandled exceptions thrown by middleware, logs and returns a 500 + /// public class ExceptionHandlerMiddleware { private readonly RequestDelegate _next; diff --git a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs index 6bce4ac6..10a10c66 100644 --- a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs +++ b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs @@ -1,73 +1,73 @@ -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 ResponderMiddleware : OcelotMiddleware - { - private readonly RequestDelegate _next; - private readonly IHttpResponder _responder; - private readonly IErrorsToHttpStatusCodeMapper _codeMapper; - private readonly IOcelotLogger _logger; - - public ResponderMiddleware(RequestDelegate next, - IHttpResponder responder, - IOcelotLoggerFactory loggerFactory, - IRequestScopedDataRepository requestScopedDataRepository, - IErrorsToHttpStatusCodeMapper codeMapper) - :base(requestScopedDataRepository) - { - _next = next; - _responder = responder; - _codeMapper = codeMapper; - _logger = loggerFactory.CreateLogger(); - - } - - public async Task Invoke(HttpContext context) - { - _logger.LogDebug("started error responder middleware"); - - await _next.Invoke(context); - - _logger.LogDebug("calling next middleware"); - - if (PipelineError) - { - _logger.LogDebug("there is a pipeline error, getting errors"); - - var errors = PipelineErrors; - - _logger.LogDebug("received errors setting error response"); - - SetErrorResponse(context, errors); - } - else - { - _logger.LogDebug("no pipeline error, setting response"); - - await _responder.SetResponseOnHttpContext(context, HttpResponseMessage); - } - } - - private void SetErrorResponse(HttpContext context, List errors) - { - var statusCode = _codeMapper.Map(errors); - - if (!statusCode.IsError) - { - _responder.SetErrorResponseOnContext(context, statusCode.Data); - } - else - { - _responder.SetErrorResponseOnContext(context, 500); - } - } - } +using System.Collections.Generic; +using System.Threading.Tasks; +using Microsoft.AspNetCore.Http; +using Ocelot.Errors; +using Ocelot.Infrastructure.RequestData; +using Ocelot.Logging; +using Ocelot.Middleware; + +namespace Ocelot.Responder.Middleware +{ + /// + /// Completes and returns the request and request body, if any pipeline errors occured then sets the appropriate HTTP status code instead. + /// + public class ResponderMiddleware : OcelotMiddleware + { + private readonly RequestDelegate _next; + private readonly IHttpResponder _responder; + private readonly IErrorsToHttpStatusCodeMapper _codeMapper; + private readonly IOcelotLogger _logger; + + public ResponderMiddleware(RequestDelegate next, + IHttpResponder responder, + IOcelotLoggerFactory loggerFactory, + IRequestScopedDataRepository requestScopedDataRepository, + IErrorsToHttpStatusCodeMapper codeMapper) + :base(requestScopedDataRepository) + { + _next = next; + _responder = responder; + _codeMapper = codeMapper; + _logger = loggerFactory.CreateLogger(); + + } + + public async Task Invoke(HttpContext context) + { + _logger.LogDebug($"entered {this.GetType().Name}"); + _logger.LogDebug($"invoking next middleware from {this.GetType().Name}"); + + await _next.Invoke(context); + + _logger.LogDebug($"returned to {this.GetType().Name} after next middleware completed"); + + if (PipelineError) + { + var errors = PipelineErrors; + _logger.LogDebug($"{errors.Count} pipeline errors found in {this.GetType().Name}. Setting error response status code"); + + SetErrorResponse(context, errors); + } + else + { + _logger.LogDebug("no pipeline errors, setting and returning completed response"); + await _responder.SetResponseOnHttpContext(context, HttpResponseMessage); + } + _logger.LogDebug($"completed {this.GetType().Name}"); + } + + private void SetErrorResponse(HttpContext context, List errors) + { + var statusCode = _codeMapper.Map(errors); + + if (!statusCode.IsError) + { + _responder.SetErrorResponseOnContext(context, statusCode.Data); + } + else + { + _responder.SetErrorResponseOnContext(context, 500); + } + } + } } \ No newline at end of file From a00788746159f42258707284291cca9efbdaa36d Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Tue, 14 Mar 2017 09:45:07 +0000 Subject: [PATCH 3/9] Add MiddelwareName into base OcelotMiddleware Following TomPallister suggestion, it makes sense to call GetType only once and in the constructor (middlewares are only instantiated once). I have also taken the oppturniuty to add it as a property on the base middleware allowing any other middleware to utlise it as well. --- src/Ocelot/Middleware/OcelotMiddleware.cs | 3 +++ src/Ocelot/Responder/Middleware/ResponderMiddleware.cs | 10 +++++----- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/src/Ocelot/Middleware/OcelotMiddleware.cs b/src/Ocelot/Middleware/OcelotMiddleware.cs index b8937108..2926e543 100644 --- a/src/Ocelot/Middleware/OcelotMiddleware.cs +++ b/src/Ocelot/Middleware/OcelotMiddleware.cs @@ -14,8 +14,11 @@ namespace Ocelot.Middleware protected OcelotMiddleware(IRequestScopedDataRepository requestScopedDataRepository) { _requestScopedDataRepository = requestScopedDataRepository; + MiddlwareName = this.GetType().Name; } + public string MiddlwareName { get; } + public bool PipelineError { get diff --git a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs index 10a10c66..1605fb06 100644 --- a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs +++ b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs @@ -34,17 +34,17 @@ namespace Ocelot.Responder.Middleware public async Task Invoke(HttpContext context) { - _logger.LogDebug($"entered {this.GetType().Name}"); - _logger.LogDebug($"invoking next middleware from {this.GetType().Name}"); + _logger.LogDebug($"entered {MiddlwareName}"); + _logger.LogDebug($"invoking next middleware from {MiddlwareName}"); await _next.Invoke(context); - _logger.LogDebug($"returned to {this.GetType().Name} after next middleware completed"); + _logger.LogDebug($"returned to {MiddlwareName} after next middleware completed"); if (PipelineError) { var errors = PipelineErrors; - _logger.LogDebug($"{errors.Count} pipeline errors found in {this.GetType().Name}. Setting error response status code"); + _logger.LogDebug($"{errors.Count} pipeline errors found in {MiddlwareName}. Setting error response status code"); SetErrorResponse(context, errors); } @@ -53,7 +53,7 @@ namespace Ocelot.Responder.Middleware _logger.LogDebug("no pipeline errors, setting and returning completed response"); await _responder.SetResponseOnHttpContext(context, HttpResponseMessage); } - _logger.LogDebug($"completed {this.GetType().Name}"); + _logger.LogDebug($"completed {MiddlwareName}"); } private void SetErrorResponse(HttpContext context, List errors) From c01f778bf9ad715e29a407c40f37ffa67b73f367 Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Tue, 14 Mar 2017 10:06:53 +0000 Subject: [PATCH 4/9] Add LogTrace to IOcelotLogger Previously only LogDebug and LogError were implemented, however this could/will lead to very noisy logging. Implementing trace should allow a better seperation when debugging. --- src/Ocelot/Logging/IOcelotLoggerFactory.cs | 6 ++++++ src/Ocelot/Responder/Middleware/ResponderMiddleware.cs | 6 +++--- 2 files changed, 9 insertions(+), 3 deletions(-) diff --git a/src/Ocelot/Logging/IOcelotLoggerFactory.cs b/src/Ocelot/Logging/IOcelotLoggerFactory.cs index 5305088f..50e5b25e 100644 --- a/src/Ocelot/Logging/IOcelotLoggerFactory.cs +++ b/src/Ocelot/Logging/IOcelotLoggerFactory.cs @@ -29,6 +29,7 @@ namespace Ocelot.Logging public interface IOcelotLogger { + void LogTrace(string message, params object[] args); void LogDebug(string message, params object[] args); void LogError(string message, Exception exception); } @@ -44,6 +45,11 @@ namespace Ocelot.Logging _scopedDataRepository = scopedDataRepository; } + public void LogTrace(string message, params object[] args) + { + _logger.LogTrace(GetMessageWithOcelotRequestId(message), args); + } + public void LogDebug(string message, params object[] args) { _logger.LogDebug(GetMessageWithOcelotRequestId(message), args); diff --git a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs index 1605fb06..2e6585d6 100644 --- a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs +++ b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs @@ -34,11 +34,11 @@ namespace Ocelot.Responder.Middleware public async Task Invoke(HttpContext context) { - _logger.LogDebug($"entered {MiddlwareName}"); + _logger.LogTrace($"entered {MiddlwareName}"); _logger.LogDebug($"invoking next middleware from {MiddlwareName}"); await _next.Invoke(context); - + _logger.LogDebug($"returned to {MiddlwareName} after next middleware completed"); if (PipelineError) @@ -53,7 +53,7 @@ namespace Ocelot.Responder.Middleware _logger.LogDebug("no pipeline errors, setting and returning completed response"); await _responder.SetResponseOnHttpContext(context, HttpResponseMessage); } - _logger.LogDebug($"completed {MiddlwareName}"); + _logger.LogTrace($"completed {MiddlwareName}"); } private void SetErrorResponse(HttpContext context, List errors) From 0ad41aa3fac8fc69776ddf14beae0b3d4f3c8737 Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Tue, 14 Mar 2017 11:52:44 +0000 Subject: [PATCH 5/9] Add LogError(string) to logger Added LogError(string) to interface as sometimes there isn't an exception to be logged. Additionally, split Logger and LoggerFactory implementations into seperate files just for tidiness. Additonally added some very basic unit tests to the HttpDataRepository as a bit of regression safety and to prove that Get never returns a null. Slightly refactored the logic within AspDotNetLogger under GetMessageWithOcelotRequestId so that the if statement is a little easier to read. Attempted to remove the requestId == null, however this broke numerous tests as the mocks don't set the behviour for dataReposioty getting the requestId --- src/Ocelot/Logging/AspDotNetLogger.cs | 49 +++++++++++++ src/Ocelot/Logging/AspDotNetLoggerFactory.cs | 23 ++++++ src/Ocelot/Logging/IOcelotLoggerFactory.cs | 64 +--------------- .../Middleware/ResponderMiddleware.cs | 6 +- .../Infrastructure/HttpDataRepositoryTests.cs | 73 +++++++++++++++++++ 5 files changed, 152 insertions(+), 63 deletions(-) create mode 100644 src/Ocelot/Logging/AspDotNetLogger.cs create mode 100644 src/Ocelot/Logging/AspDotNetLoggerFactory.cs create mode 100644 test/Ocelot.UnitTests/Infrastructure/HttpDataRepositoryTests.cs diff --git a/src/Ocelot/Logging/AspDotNetLogger.cs b/src/Ocelot/Logging/AspDotNetLogger.cs new file mode 100644 index 00000000..c4185c23 --- /dev/null +++ b/src/Ocelot/Logging/AspDotNetLogger.cs @@ -0,0 +1,49 @@ +using System; +using Microsoft.Extensions.Logging; +using Ocelot.Infrastructure.RequestData; + +namespace Ocelot.Logging +{ + public class AspDotNetLogger : IOcelotLogger + { + private readonly ILogger _logger; + private readonly IRequestScopedDataRepository _scopedDataRepository; + + public AspDotNetLogger(ILogger logger, IRequestScopedDataRepository scopedDataRepository) + { + _logger = logger; + _scopedDataRepository = scopedDataRepository; + } + + public void LogTrace(string message, params object[] args) + { + _logger.LogTrace(GetMessageWithOcelotRequestId(message), args); + } + + public void LogDebug(string message, params object[] args) + { + _logger.LogDebug(GetMessageWithOcelotRequestId(message), args); + } + public void LogError(string message, Exception exception) + { + _logger.LogError(GetMessageWithOcelotRequestId(message), exception); + } + + public void LogError(string message, params object[] args) + { + _logger.LogError(GetMessageWithOcelotRequestId(message), args); + } + + private string GetMessageWithOcelotRequestId(string message) + { + var requestId = _scopedDataRepository.Get("RequestId"); + + if (requestId == null || requestId.IsError) + { + return $"{message} : OcelotRequestId - not set"; + } + + return $"{message} : OcelotRequestId - {requestId.Data}"; + } + } +} \ No newline at end of file diff --git a/src/Ocelot/Logging/AspDotNetLoggerFactory.cs b/src/Ocelot/Logging/AspDotNetLoggerFactory.cs new file mode 100644 index 00000000..91435740 --- /dev/null +++ b/src/Ocelot/Logging/AspDotNetLoggerFactory.cs @@ -0,0 +1,23 @@ +using Microsoft.Extensions.Logging; +using Ocelot.Infrastructure.RequestData; + +namespace Ocelot.Logging +{ + public class AspDotNetLoggerFactory : IOcelotLoggerFactory + { + private readonly ILoggerFactory _loggerFactory; + private readonly IRequestScopedDataRepository _scopedDataRepository; + + public AspDotNetLoggerFactory(ILoggerFactory loggerFactory, IRequestScopedDataRepository scopedDataRepository) + { + _loggerFactory = loggerFactory; + _scopedDataRepository = scopedDataRepository; + } + + public IOcelotLogger CreateLogger() + { + var logger = _loggerFactory.CreateLogger(); + return new AspDotNetLogger(logger, _scopedDataRepository); + } + } +} \ No newline at end of file diff --git a/src/Ocelot/Logging/IOcelotLoggerFactory.cs b/src/Ocelot/Logging/IOcelotLoggerFactory.cs index 50e5b25e..98326648 100644 --- a/src/Ocelot/Logging/IOcelotLoggerFactory.cs +++ b/src/Ocelot/Logging/IOcelotLoggerFactory.cs @@ -1,6 +1,4 @@ using System; -using Microsoft.Extensions.Logging; -using Ocelot.Infrastructure.RequestData; namespace Ocelot.Logging { @@ -8,68 +6,14 @@ namespace Ocelot.Logging { IOcelotLogger CreateLogger(); } - - public class AspDotNetLoggerFactory : IOcelotLoggerFactory - { - private readonly ILoggerFactory _loggerFactory; - private readonly IRequestScopedDataRepository _scopedDataRepository; - - public AspDotNetLoggerFactory(ILoggerFactory loggerFactory, IRequestScopedDataRepository scopedDataRepository) - { - _loggerFactory = loggerFactory; - _scopedDataRepository = scopedDataRepository; - } - - public IOcelotLogger CreateLogger() - { - var logger = _loggerFactory.CreateLogger(); - return new AspDotNetLogger(logger, _scopedDataRepository); - } - } - + /// + /// Thin wrapper around the DotNet core logging framework, used to allow the scopedDataRepository to be injected giving access to the Ocelot RequestId + /// public interface IOcelotLogger { void LogTrace(string message, params object[] args); void LogDebug(string message, params object[] args); void LogError(string message, Exception exception); - } - - public class AspDotNetLogger : IOcelotLogger - { - private readonly ILogger _logger; - private readonly IRequestScopedDataRepository _scopedDataRepository; - - public AspDotNetLogger(ILogger logger, IRequestScopedDataRepository scopedDataRepository) - { - _logger = logger; - _scopedDataRepository = scopedDataRepository; - } - - public void LogTrace(string message, params object[] args) - { - _logger.LogTrace(GetMessageWithOcelotRequestId(message), args); - } - - public void LogDebug(string message, params object[] args) - { - _logger.LogDebug(GetMessageWithOcelotRequestId(message), args); - } - - public void LogError(string message, Exception exception) - { - _logger.LogError(GetMessageWithOcelotRequestId(message), exception); - } - - private string GetMessageWithOcelotRequestId(string message) - { - var requestId = _scopedDataRepository.Get("RequestId"); - - if (requestId != null && !requestId.IsError) - { - return $"{message} : OcelotRequestId - {requestId.Data}"; - - } - return $"{message} : OcelotRequestId - not set"; - } + void LogError(string message, params object[] args); } } diff --git a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs index 2e6585d6..a15bb68b 100644 --- a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs +++ b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs @@ -35,16 +35,16 @@ namespace Ocelot.Responder.Middleware public async Task Invoke(HttpContext context) { _logger.LogTrace($"entered {MiddlwareName}"); - _logger.LogDebug($"invoking next middleware from {MiddlwareName}"); + _logger.LogTrace($"invoking next middleware from {MiddlwareName}"); await _next.Invoke(context); - _logger.LogDebug($"returned to {MiddlwareName} after next middleware completed"); + _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); if (PipelineError) { var errors = PipelineErrors; - _logger.LogDebug($"{errors.Count} pipeline errors found in {MiddlwareName}. Setting error response status code"); + _logger.LogError($"{errors.Count} pipeline errors found in {MiddlwareName}. Setting error response status code"); SetErrorResponse(context, errors); } diff --git a/test/Ocelot.UnitTests/Infrastructure/HttpDataRepositoryTests.cs b/test/Ocelot.UnitTests/Infrastructure/HttpDataRepositoryTests.cs new file mode 100644 index 00000000..0d7c9201 --- /dev/null +++ b/test/Ocelot.UnitTests/Infrastructure/HttpDataRepositoryTests.cs @@ -0,0 +1,73 @@ +using Microsoft.AspNetCore.Http; +using Ocelot.Infrastructure.RequestData; +using Ocelot.Responses; +using Shouldly; +using TestStack.BDDfy; +using Xunit; + +namespace Ocelot.UnitTests.Infrastructure +{ + public class HttpDataRepositoryTests + { + private HttpContext _httpContext; + private IHttpContextAccessor _httpContextAccessor; + private HttpDataRepository _httpDataRepository; + private object _result; + + public HttpDataRepositoryTests() + { + _httpContext = new DefaultHttpContext(); + _httpContextAccessor = new HttpContextAccessor{HttpContext = _httpContext}; + _httpDataRepository = new HttpDataRepository(_httpContextAccessor); + } + + //TODO - Additional tests -> Type mistmatch aka Add string, request int + //TODO - Additional tests -> HttpContent null. This should never happen + + [Fact] + public void Get_returns_correct_key_from_http_context() + { + + this.Given(x => x.GivenAHttpContextContaining("key", "string")) + .When(x => x.GetIsCalledWithKey("key")) + .Then(x => x.ThenTheResultIsAnOkResponse("string")) + .BDDfy(); + } + + [Fact] + public void Get_returns_error_response_if_the_key_is_not_found() //Therefore does not return null + { + this.Given(x => x.GivenAHttpContextContaining("key", "string")) + .When(x => x.GetIsCalledWithKey("keyDoesNotExist")) + .Then(x => x.ThenTheResultIsAnErrorReposnse("string1")) + .BDDfy(); + } + + private void GivenAHttpContextContaining(string key, object o) + { + _httpContext.Items.Add(key, o); + } + + private void GetIsCalledWithKey(string key) + { + _result = _httpDataRepository.Get(key); + } + + private void ThenTheResultIsAnErrorReposnse(object resultValue) + { + _result.ShouldBeOfType>(); + ((ErrorResponse) _result).Data.ShouldBeNull(); + ((ErrorResponse)_result).IsError.ShouldBe(true); + ((ErrorResponse) _result).Errors.ShouldHaveSingleItem() + .ShouldBeOfType() + .Message.ShouldStartWith("Unable to find data for key: "); + } + + private void ThenTheResultIsAnOkResponse(object resultValue) + { + _result.ShouldBeOfType>(); + ((OkResponse)_result).Data.ShouldBe(resultValue); + } + + } +} From 9774580c4e540e05d6016b80f171e1e4ebe54e63 Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Tue, 14 Mar 2017 17:43:24 +0000 Subject: [PATCH 6/9] 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); } } From ad81b7a305befc7bf6364ff3dd82492122c4194f Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Sat, 18 Mar 2017 18:30:09 +0000 Subject: [PATCH 7/9] Update OcelotLogger to accept name of class OcelotLogger now has a property called "Name" intended to store the name of the type for which the logger has been built for. This is intended to keep the code a little bit cleaner and also allows for a few extention methods for common logging scenarios --- src/Ocelot/Logging/AspDotNetLogger.cs | 21 ++++++++------ src/Ocelot/Logging/AspDotNetLoggerFactory.cs | 2 +- src/Ocelot/Logging/IOcelotLoggerFactory.cs | 5 ++++ src/Ocelot/Logging/OcelotLoggerExtensions.cs | 29 ++++++++++++++++++++ 4 files changed, 47 insertions(+), 10 deletions(-) create mode 100644 src/Ocelot/Logging/OcelotLoggerExtensions.cs diff --git a/src/Ocelot/Logging/AspDotNetLogger.cs b/src/Ocelot/Logging/AspDotNetLogger.cs index c4185c23..9ebaf7fd 100644 --- a/src/Ocelot/Logging/AspDotNetLogger.cs +++ b/src/Ocelot/Logging/AspDotNetLogger.cs @@ -9,8 +9,11 @@ namespace Ocelot.Logging private readonly ILogger _logger; private readonly IRequestScopedDataRepository _scopedDataRepository; - public AspDotNetLogger(ILogger logger, IRequestScopedDataRepository scopedDataRepository) - { + public string Name { get; } + + public AspDotNetLogger(ILogger logger, IRequestScopedDataRepository scopedDataRepository, string typeName) + { + Name = typeName; _logger = logger; _scopedDataRepository = scopedDataRepository; } @@ -34,16 +37,16 @@ namespace Ocelot.Logging _logger.LogError(GetMessageWithOcelotRequestId(message), args); } - private string GetMessageWithOcelotRequestId(string message) - { - var requestId = _scopedDataRepository.Get("RequestId"); - - if (requestId == null || requestId.IsError) + private string GetMessageWithOcelotRequestId(string message) + { + var requestId = _scopedDataRepository.Get("RequestId"); + + if (requestId == null || requestId.IsError) { return $"{message} : OcelotRequestId - not set"; } - return $"{message} : OcelotRequestId - {requestId.Data}"; - } + return $"{message} : OcelotRequestId - {requestId.Data}"; + } } } \ No newline at end of file diff --git a/src/Ocelot/Logging/AspDotNetLoggerFactory.cs b/src/Ocelot/Logging/AspDotNetLoggerFactory.cs index 91435740..298653bc 100644 --- a/src/Ocelot/Logging/AspDotNetLoggerFactory.cs +++ b/src/Ocelot/Logging/AspDotNetLoggerFactory.cs @@ -17,7 +17,7 @@ namespace Ocelot.Logging public IOcelotLogger CreateLogger() { var logger = _loggerFactory.CreateLogger(); - return new AspDotNetLogger(logger, _scopedDataRepository); + return new AspDotNetLogger(logger, _scopedDataRepository, typeof(T).Name); } } } \ No newline at end of file diff --git a/src/Ocelot/Logging/IOcelotLoggerFactory.cs b/src/Ocelot/Logging/IOcelotLoggerFactory.cs index 98326648..88bfdcd9 100644 --- a/src/Ocelot/Logging/IOcelotLoggerFactory.cs +++ b/src/Ocelot/Logging/IOcelotLoggerFactory.cs @@ -15,5 +15,10 @@ namespace Ocelot.Logging void LogDebug(string message, params object[] args); void LogError(string message, Exception exception); void LogError(string message, params object[] args); + + /// + /// The name of the type the logger has been built for. + /// + string Name { get; } } } diff --git a/src/Ocelot/Logging/OcelotLoggerExtensions.cs b/src/Ocelot/Logging/OcelotLoggerExtensions.cs new file mode 100644 index 00000000..05bd4565 --- /dev/null +++ b/src/Ocelot/Logging/OcelotLoggerExtensions.cs @@ -0,0 +1,29 @@ +using System; +using System.Collections.Generic; +using System.Text; + +namespace Ocelot.Logging +{ + public static class OcelotLoggerExtensions + { + public static void TraceMiddlewareEntry(this IOcelotLogger logger) + { + logger.LogTrace($"entered {logger.Name}"); + } + + public static void TraceInvokeNext(this IOcelotLogger logger) + { + logger.LogTrace($"invoking next middleware from {logger.Name}"); + } + + public static void TraceInvokeNextCompleted(this IOcelotLogger logger) + { + logger.LogTrace($"returned to {logger.Name} after next middleware completed"); + } + + public static void TraceMiddlewareCompleted(this IOcelotLogger logger) + { + logger.LogTrace($"completed {logger.Name}"); + } + } +} From 34be5a29558c3d61b9340a58c1ac2ead3bb2cf29 Mon Sep 17 00:00:00 2001 From: Marc Denman Date: Sat, 18 Mar 2017 18:33:51 +0000 Subject: [PATCH 8/9] Update middelware to use logging extension methods --- .../Middleware/AuthenticationMiddleware.cs | 24 +++++++------- .../DownstreamRouteFinderMiddleware.cs | 10 +++--- .../Middleware/ClientRateLimitMiddleware.cs | 31 ++++++++++++------- .../Middleware/RequestIdMiddleware.cs | 12 +++---- .../Middleware/ResponderMiddleware.cs | 12 +++---- test/Ocelot.ManualTest/appsettings.json | 2 +- 6 files changed, 48 insertions(+), 43 deletions(-) diff --git a/src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs b/src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs index da4af616..a6eb9cc2 100644 --- a/src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs +++ b/src/Ocelot/Authentication/Middleware/AuthenticationMiddleware.cs @@ -34,7 +34,7 @@ namespace Ocelot.Authentication.Middleware public async Task Invoke(HttpContext context) { - _logger.LogTrace($"entered {MiddlwareName}"); + _logger.TraceMiddlewareEntry(); if (IsAuthenticatedRoute(DownstreamRoute.ReRoute)) { @@ -46,6 +46,7 @@ namespace Ocelot.Authentication.Middleware { _logger.LogError($"Error getting authentication handler for {context.Request.Path}. {authenticationHandler.Errors.ToErrorString()}"); SetPipelineError(authenticationHandler.Errors); + _logger.TraceMiddlewareCompleted(); return; } @@ -55,12 +56,11 @@ namespace Ocelot.Authentication.Middleware if (context.User.Identity.IsAuthenticated) { _logger.LogDebug($"Client has been authenticated for {context.Request.Path}"); - _logger.LogTrace($"{MiddlwareName} invoking next middleware"); - await _next.Invoke(context); - - _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); - _logger.LogTrace($"completed {MiddlwareName}"); + _logger.TraceInvokeNext(); + await _next.Invoke(context); + _logger.TraceInvokeNextCompleted(); + _logger.TraceMiddlewareCompleted(); } else { @@ -73,18 +73,18 @@ namespace Ocelot.Authentication.Middleware _logger.LogError($"Client has NOT been authenticated for {context.Request.Path} and pipeline error set. {error.ToErrorString()}"); SetPipelineError(error); - _logger.LogTrace($"completed {MiddlwareName}"); + _logger.TraceMiddlewareCompleted(); return; } } else { - _logger.LogTrace($"No authentication needed for {context.Request.Path}. Invoking next middleware from {MiddlwareName}"); + _logger.LogTrace($"No authentication needed for {context.Request.Path}"); - await _next.Invoke(context); - - _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); - _logger.LogTrace($"completed {MiddlwareName}"); + _logger.TraceInvokeNext(); + await _next.Invoke(context); + _logger.TraceInvokeNextCompleted(); + _logger.TraceMiddlewareCompleted(); } } diff --git a/src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs b/src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs index 79ed899d..a3a4776d 100644 --- a/src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs +++ b/src/Ocelot/DownstreamRouteFinder/Middleware/DownstreamRouteFinderMiddleware.cs @@ -30,7 +30,7 @@ namespace Ocelot.DownstreamRouteFinder.Middleware public async Task Invoke(HttpContext context) { - _logger.LogTrace($"entered {MiddlwareName}"); + _logger.TraceMiddlewareEntry(); var upstreamUrlPath = context.Request.Path.ToString().SetLastCharacterAs('/'); @@ -43,6 +43,8 @@ namespace Ocelot.DownstreamRouteFinder.Middleware _logger.LogError($"{MiddlwareName} setting pipeline errors. IDownstreamRouteFinder returned {downstreamRoute.Errors.ToErrorString()}"); SetPipelineError(downstreamRoute.Errors); + + _logger.TraceMiddlewareCompleted(); return; } @@ -50,12 +52,12 @@ namespace Ocelot.DownstreamRouteFinder.Middleware SetDownstreamRouteForThisRequest(downstreamRoute.Data); - _logger.LogTrace($"invoking next middleware from {MiddlwareName}"); + _logger.TraceInvokeNext(); await _next.Invoke(context); - _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); - _logger.LogTrace($"completed {MiddlwareName}"); + _logger.TraceInvokeNextCompleted(); + _logger.TraceMiddlewareCompleted(); } } } \ No newline at end of file diff --git a/src/Ocelot/RateLimit/Middleware/ClientRateLimitMiddleware.cs b/src/Ocelot/RateLimit/Middleware/ClientRateLimitMiddleware.cs index f9cb72b5..02a37e36 100644 --- a/src/Ocelot/RateLimit/Middleware/ClientRateLimitMiddleware.cs +++ b/src/Ocelot/RateLimit/Middleware/ClientRateLimitMiddleware.cs @@ -31,14 +31,18 @@ namespace Ocelot.RateLimit.Middleware public async Task Invoke(HttpContext context) { - _logger.LogTrace($"entered {MiddlwareName}"); + _logger.TraceMiddlewareEntry(); 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); + _logger.LogDebug($"EndpointRateLimiting is not enabled for {DownstreamRoute.ReRoute.DownstreamPathTemplate}"); + + _logger.TraceInvokeNext(); + await _next.Invoke(context); + _logger.TraceInvokeNextCompleted(); + _logger.TraceMiddlewareCompleted(); return; } // compute identity from request @@ -47,8 +51,12 @@ 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); + _logger.LogDebug($"{DownstreamRoute.ReRoute.DownstreamPathTemplate} is white listed from rate limiting"); + + _logger.TraceInvokeNext(); + await _next.Invoke(context); + _logger.TraceInvokeNextCompleted(); + _logger.TraceMiddlewareCompleted(); return; } @@ -69,6 +77,7 @@ namespace Ocelot.RateLimit.Middleware // break execution await ReturnQuotaExceededResponse(context, options, retryAfter); + _logger.TraceMiddlewareCompleted(); return; } } @@ -77,14 +86,12 @@ namespace Ocelot.RateLimit.Middleware { var headers = _processor.GetRateLimitHeaders( context,identity, options); context.Response.OnStarting(SetRateLimitHeaders, state: headers); - } - - _logger.LogTrace($"invoking next middleware from {MiddlwareName}"); - - await _next.Invoke(context); + } - _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); - _logger.LogTrace($"completed {MiddlwareName}"); + _logger.TraceInvokeNext(); + await _next.Invoke(context); + _logger.TraceInvokeNextCompleted(); + _logger.TraceMiddlewareCompleted(); } 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 d6e493ae..1e1a955c 100644 --- a/src/Ocelot/RequestId/Middleware/RequestIdMiddleware.cs +++ b/src/Ocelot/RequestId/Middleware/RequestIdMiddleware.cs @@ -26,18 +26,16 @@ namespace Ocelot.RequestId.Middleware public async Task Invoke(HttpContext context) { - _logger.LogTrace($"entered {MiddlwareName}"); + _logger.TraceMiddlewareEntry(); SetOcelotRequestId(context); _logger.LogDebug("set requestId"); - _logger.LogTrace($"invoking next middleware from {MiddlwareName}"); - - await _next.Invoke(context); - - _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); - _logger.LogTrace($"completed {MiddlwareName}"); + _logger.TraceInvokeNext(); + await _next.Invoke(context); + _logger.TraceInvokeNextCompleted(); + _logger.TraceMiddlewareCompleted(); } private void SetOcelotRequestId(HttpContext context) diff --git a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs index f086b566..7e843486 100644 --- a/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs +++ b/src/Ocelot/Responder/Middleware/ResponderMiddleware.cs @@ -34,12 +34,10 @@ namespace Ocelot.Responder.Middleware public async Task Invoke(HttpContext context) { - _logger.LogTrace($"entered {MiddlwareName}"); - _logger.LogTrace($"invoking next middleware from {MiddlwareName}"); - - await _next.Invoke(context); - - _logger.LogTrace($"returned to {MiddlwareName} after next middleware completed"); + _logger.TraceMiddlewareEntry(); + _logger.TraceInvokeNext(); + await _next.Invoke(context); + _logger.TraceInvokeNextCompleted(); if (PipelineError) { @@ -53,7 +51,7 @@ namespace Ocelot.Responder.Middleware _logger.LogDebug("no pipeline errors, setting and returning completed response"); await _responder.SetResponseOnHttpContext(context, HttpResponseMessage); } - _logger.LogTrace($"completed {MiddlwareName}"); + _logger.TraceMiddlewareCompleted(); } private void SetErrorResponse(HttpContext context, List errors) diff --git a/test/Ocelot.ManualTest/appsettings.json b/test/Ocelot.ManualTest/appsettings.json index d73b7dcb..7327a7b9 100644 --- a/test/Ocelot.ManualTest/appsettings.json +++ b/test/Ocelot.ManualTest/appsettings.json @@ -2,7 +2,7 @@ "Logging": { "IncludeScopes": true, "LogLevel": { - "Default": "Debug", + "Default": "Trace", "System": "Information", "Microsoft": "Information" } From be0918879c132f106f2c1d9fc19ccd6de9765815 Mon Sep 17 00:00:00 2001 From: TomPallister Date: Sun, 19 Mar 2017 12:46:42 +0000 Subject: [PATCH 9/9] Change to not log loads of rubbish when running integration tests --- test/Ocelot.IntegrationTests/appsettings.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/Ocelot.IntegrationTests/appsettings.json b/test/Ocelot.IntegrationTests/appsettings.json index d73b7dcb..503cc778 100644 --- a/test/Ocelot.IntegrationTests/appsettings.json +++ b/test/Ocelot.IntegrationTests/appsettings.json @@ -2,7 +2,7 @@ "Logging": { "IncludeScopes": true, "LogLevel": { - "Default": "Debug", + "Default": "Error", "System": "Information", "Microsoft": "Information" }