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" }