From c68384481763e69cc2b36083d519e1556428b7f3 Mon Sep 17 00:00:00 2001 From: Ryan Nowak Date: Thu, 6 Sep 2018 22:00:47 -0700 Subject: [PATCH] Fix #553 - Add logging for new LinkGenerator Adds logging for all of the failure cases of link generation. --- samples/RoutingSample.Web/Program.cs | 4 +- .../RoutingSample.Web.csproj | 1 + .../DefaultLinkGenerator.cs | 190 +++++++++++++++++- 3 files changed, 189 insertions(+), 6 deletions(-) diff --git a/samples/RoutingSample.Web/Program.cs b/samples/RoutingSample.Web/Program.cs index 5867596559..1fa90c645c 100644 --- a/samples/RoutingSample.Web/Program.cs +++ b/samples/RoutingSample.Web/Program.cs @@ -4,6 +4,7 @@ using System; using Microsoft.AspNetCore.Builder; using Microsoft.AspNetCore.Hosting; +using Microsoft.Extensions.Logging; namespace RoutingSample.Web { @@ -59,7 +60,8 @@ namespace RoutingSample.Web return new WebHostBuilder() .UseKestrel() .UseIISIntegration() - .UseStartup(startupType); + .UseStartup(startupType) + .ConfigureLogging(l => l.AddConsole().SetMinimumLevel(LogLevel.Debug)); } } } diff --git a/samples/RoutingSample.Web/RoutingSample.Web.csproj b/samples/RoutingSample.Web/RoutingSample.Web.csproj index 52b1699c7b..d8cc8e8283 100644 --- a/samples/RoutingSample.Web/RoutingSample.Web.csproj +++ b/samples/RoutingSample.Web/RoutingSample.Web.csproj @@ -10,6 +10,7 @@ + diff --git a/src/Microsoft.AspNetCore.Routing/DefaultLinkGenerator.cs b/src/Microsoft.AspNetCore.Routing/DefaultLinkGenerator.cs index df52926a02..f050eecb97 100644 --- a/src/Microsoft.AspNetCore.Routing/DefaultLinkGenerator.cs +++ b/src/Microsoft.AspNetCore.Routing/DefaultLinkGenerator.cs @@ -4,6 +4,7 @@ using System; using System.Collections.Generic; using System.Linq; +using System.Text; using System.Text.Encodings.Web; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http.Extensions; @@ -19,7 +20,6 @@ namespace Microsoft.AspNetCore.Routing { internal sealed class DefaultLinkGenerator : LinkGenerator { - private static readonly char[] UrlQueryDelimiters = new char[] { '?', '#' }; private readonly ParameterPolicyFactory _parameterPolicyFactory; private readonly ObjectPool _uriBuildingContextPool; private readonly ILogger _logger; @@ -172,7 +172,18 @@ namespace Microsoft.AspNetCore.Routing private List GetEndpoints(TAddress address) { var addressingScheme = _serviceProvider.GetRequiredService>(); - return addressingScheme.FindEndpoints(address).OfType().ToList(); + var endpoints = addressingScheme.FindEndpoints(address).OfType().ToList(); + + if (endpoints.Count == 0) + { + Log.EndpointsNotFound(_logger, address); + } + else + { + Log.EndpointsFound(_logger, address, endpoints); + } + + return endpoints; } // Also called from DefaultLinkGenerationTemplate @@ -195,15 +206,17 @@ namespace Microsoft.AspNetCore.Routing options, out var result)) { - - return UriHelper.BuildRelative( + var uri = UriHelper.BuildRelative( pathBase, result.path, result.query, fragment); + Log.LinkGenerationSucceeded(_logger, endpoints, uri); + return uri; } } + Log.LinkGenerationFailed(_logger, endpoints); return null; } @@ -229,16 +242,19 @@ namespace Microsoft.AspNetCore.Routing options, out var result)) { - return UriHelper.BuildAbsolute( + var uri = UriHelper.BuildAbsolute( scheme, host, pathBase, result.path, result.query, fragment); + Log.LinkGenerationSucceeded(_logger, endpoints, uri); + return uri; } } + Log.LinkGenerationFailed(_logger, endpoints); return null; } @@ -266,20 +282,25 @@ namespace Microsoft.AspNetCore.Routing { // We're missing one of the required values for this route. result = default; + Log.TemplateFailedRequiredValues(_logger, endpoint, ambientValues, explicitValues); return false; } if (!MatchesConstraints(httpContext, endpoint, templateValuesResult.CombinedValues)) { result = default; + + // MatchesConstraints does its own logging, so we're not logging here. return false; } if (!templateBinder.TryBindValues(templateValuesResult.AcceptedValues, options, _globalLinkOptions, out result)) { + Log.TemplateFailedExpansion(_logger, endpoint, templateValuesResult.AcceptedValues); return false; } + Log.TemplateSucceeded(_logger, endpoint, result.path, result.query); return true; } @@ -304,6 +325,7 @@ namespace Microsoft.AspNetCore.Routing if (parameterPolicy is IRouteConstraint routeConstraint && !routeConstraint.Match(httpContext, NullRouter.Instance, kvp.Key, routeValues, RouteDirection.UrlGeneration)) { + Log.TemplateFailedConstraint(_logger, endpoint, kvp.Key, routeConstraint, routeValues); return false; } } @@ -317,5 +339,163 @@ namespace Microsoft.AspNetCore.Routing { return httpContext?.Features.Get()?.RouteValues; } + + private static class Log + { + public static class EventIds + { + public static readonly EventId EndpointsFound = new EventId(100, "EndpointsFound"); + public static readonly EventId EndpointsNotFound = new EventId(101, "EndpointsNotFound"); + + public static readonly EventId TemplateSucceeded = new EventId(102, "TemplateSucceeded"); + public static readonly EventId TemplateFailedRequiredValues = new EventId(103, "TemplateFailedRequiredValues"); + public static readonly EventId TemplateFailedConstraint = new EventId(103, "TemplateFailedConstraint"); + public static readonly EventId TemplateFailedExpansion = new EventId(104, "TemplateFailedExpansion"); + + public static readonly EventId LinkGenerationSucceeded = new EventId(105, "LinkGenerationSucceeded"); + public static readonly EventId LinkGenerationFailed = new EventId(106, "LinkGenerationFailed"); + } + + private static readonly Action, object, Exception> _endpointsFound = LoggerMessage.Define, object>( + LogLevel.Debug, + EventIds.EndpointsFound, + "Found the endpoints {Endpoints} for address {Address}"); + + private static readonly Action _endpointsNotFound = LoggerMessage.Define( + LogLevel.Debug, + EventIds.EndpointsNotFound, + "No endpoints found for address {Address}"); + + private static readonly Action _templateSucceeded = LoggerMessage.Define( + LogLevel.Debug, + EventIds.TemplateSucceeded, + "Successfully processed template {Template} for {Endpoint} resulting in {Path} and {Query}"); + + private static readonly Action _templateFailedRequiredValues = LoggerMessage.Define( + LogLevel.Debug, + EventIds.TemplateFailedRequiredValues, + "Failed to process the template {Template} for {Endpoint}. " + + "A required route value is missing, or has a different value from the required default values." + + "Supplied ambient values {AmbientValues} and {Values} with default values {Defaults}"); + + private static readonly Action _templateFailedConstraint = LoggerMessage.Define( + LogLevel.Debug, + EventIds.TemplateFailedConstraint, + "Failed to process the template {Template} for {Endpoint}. " + + "The constraint {Constraint} for parameter {ParameterName} failed with values {Values}"); + + private static readonly Action _templateFailedExpansion = LoggerMessage.Define( + LogLevel.Debug, + EventIds.TemplateFailedExpansion, + "Failed to process the template {Template} for {Endpoint}. " + + "The failure occured while expanding the template with values {Values}. " + + "This is usually due to a missing or empty value in a complex segment."); + + private static readonly Action, string, Exception> _linkGenerationSucceeded = LoggerMessage.Define, string>( + LogLevel.Debug, + EventIds.LinkGenerationSucceeded, + "Link generation succeeded for endpoints {Endpoints} with result {URI}"); + + private static readonly Action, Exception> _linkGenerationFailed = LoggerMessage.Define>( + LogLevel.Debug, + EventIds.LinkGenerationFailed, + "Link generation failed for endpoints {Endpoints}"); + + public static void EndpointsFound(ILogger logger, object address, IEnumerable endpoints) + { + // Checking level again to avoid allocation on the common path + if (logger.IsEnabled(LogLevel.Debug)) + { + _endpointsFound(logger, endpoints.Select(e => e.DisplayName), address, null); + } + } + + public static void EndpointsNotFound(ILogger logger, object address) + { + _endpointsNotFound(logger, address, null); + } + + public static void TemplateSucceeded(ILogger logger, RouteEndpoint endpoint, PathString path, QueryString query) + { + _templateSucceeded(logger, endpoint.RoutePattern.RawText, endpoint.DisplayName, path.Value, query.Value, null); + } + + public static void TemplateFailedRequiredValues(ILogger logger, RouteEndpoint endpoint, RouteValueDictionary ambientValues, RouteValueDictionary values) + { + // Checking level again to avoid allocation on the common path + if (logger.IsEnabled(LogLevel.Debug)) + { + _templateFailedRequiredValues(logger, endpoint.RoutePattern.RawText, endpoint.DisplayName, FormatRouteValues(ambientValues), FormatRouteValues(values), FormatRouteValues(endpoint.RoutePattern.Defaults), null); + } + } + + public static void TemplateFailedConstraint(ILogger logger, RouteEndpoint endpoint, string parameterName, IRouteConstraint constraint, RouteValueDictionary values) + { + // Checking level again to avoid allocation on the common path + if (logger.IsEnabled(LogLevel.Debug)) + { + _templateFailedConstraint(logger, endpoint.RoutePattern.RawText, endpoint.DisplayName, constraint, parameterName, FormatRouteValues(values), null); + } + } + + public static void TemplateFailedExpansion(ILogger logger, RouteEndpoint endpoint, RouteValueDictionary values) + { + // Checking level again to avoid allocation on the common path + if (logger.IsEnabled(LogLevel.Debug)) + { + _templateFailedExpansion(logger, endpoint.RoutePattern.RawText, endpoint.DisplayName, FormatRouteValues(values), null); + } + } + + public static void LinkGenerationSucceeded(ILogger logger, IEnumerable endpoints, string uri) + { + // Checking level again to avoid allocation on the common path + if (logger.IsEnabled(LogLevel.Debug)) + { + _linkGenerationSucceeded(logger, endpoints.Select(e => e.DisplayName), uri, null); + } + } + + public static void LinkGenerationFailed(ILogger logger, IEnumerable endpoints) + { + // Checking level again to avoid allocation on the common path + if (logger.IsEnabled(LogLevel.Debug)) + { + _linkGenerationFailed(logger, endpoints.Select(e => e.DisplayName), null); + } + } + + // EXPENSIVE: should only be used at Debug and higher levels of logging. + private static string FormatRouteValues(IReadOnlyDictionary values) + { + if (values == null || values.Count == 0) + { + return "{ }"; + } + + var builder = new StringBuilder(); + builder.Append("{ "); + + foreach (var kvp in values.OrderBy(kvp => kvp.Key)) + { + builder.Append("\""); + builder.Append(kvp.Key); + builder.Append("\""); + builder.Append(":"); + builder.Append(" "); + builder.Append("\""); + builder.Append(kvp.Value); + builder.Append("\""); + builder.Append(", "); + } + + // Trim trailing ", " + builder.Remove(builder.Length - 2, 2); + + builder.Append(" }"); + + return builder.ToString(); + } + } } }