diff --git a/src/Microsoft.AspNetCore.Routing/DefaultLinkGenerator.cs b/src/Microsoft.AspNetCore.Routing/DefaultLinkGenerator.cs index 7bd41daeaa..c652be90be 100644 --- a/src/Microsoft.AspNetCore.Routing/DefaultLinkGenerator.cs +++ b/src/Microsoft.AspNetCore.Routing/DefaultLinkGenerator.cs @@ -421,8 +421,8 @@ namespace Microsoft.AspNetCore.Routing 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."); + "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, diff --git a/src/Microsoft.AspNetCore.Routing/EndpointMiddleware.cs b/src/Microsoft.AspNetCore.Routing/EndpointMiddleware.cs index a9790e6ee1..7facd61bb0 100644 --- a/src/Microsoft.AspNetCore.Routing/EndpointMiddleware.cs +++ b/src/Microsoft.AspNetCore.Routing/EndpointMiddleware.cs @@ -57,12 +57,12 @@ namespace Microsoft.AspNetCore.Routing private static readonly Action _executingEndpoint = LoggerMessage.Define( LogLevel.Information, new EventId(0, "ExecutingEndpoint"), - "Executing endpoint '{EndpointName}'."); + "Executing endpoint '{EndpointName}'"); private static readonly Action _executedEndpoint = LoggerMessage.Define( LogLevel.Information, new EventId(1, "ExecutedEndpoint"), - "Executed endpoint '{EndpointName}'."); + "Executed endpoint '{EndpointName}'"); public static void ExecutingEndpoint(ILogger logger, Endpoint endpoint) { diff --git a/src/Microsoft.AspNetCore.Routing/EndpointRoutingMiddleware.cs b/src/Microsoft.AspNetCore.Routing/EndpointRoutingMiddleware.cs index b0d740b440..0b82dc3438 100644 --- a/src/Microsoft.AspNetCore.Routing/EndpointRoutingMiddleware.cs +++ b/src/Microsoft.AspNetCore.Routing/EndpointRoutingMiddleware.cs @@ -119,12 +119,12 @@ namespace Microsoft.AspNetCore.Routing private static readonly Action _matchSuccess = LoggerMessage.Define( LogLevel.Debug, new EventId(1, "MatchSuccess"), - "Request matched endpoint '{EndpointName}'."); + "Request matched endpoint '{EndpointName}'"); private static readonly Action _matchFailure = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "MatchFailure"), - "Request did not match any endpoints."); + "Request did not match any endpoints"); public static void MatchSuccess(ILogger logger, EndpointSelectorContext context) { diff --git a/src/Microsoft.AspNetCore.Routing/Logging/RouteConstraintMatcherExtensions.cs b/src/Microsoft.AspNetCore.Routing/Logging/RouteConstraintMatcherExtensions.cs index 9a19250f30..3036d2b9b9 100644 --- a/src/Microsoft.AspNetCore.Routing/Logging/RouteConstraintMatcherExtensions.cs +++ b/src/Microsoft.AspNetCore.Routing/Logging/RouteConstraintMatcherExtensions.cs @@ -16,7 +16,7 @@ namespace Microsoft.AspNetCore.Routing.Logging LogLevel.Debug, 1, "Route value '{RouteValue}' with key '{RouteKey}' did not match " + - "the constraint '{RouteConstraint}'."); + "the constraint '{RouteConstraint}'"); } public static void RouteValueDoesNotMatchConstraint( diff --git a/src/Microsoft.AspNetCore.Routing/Logging/RouterMiddlewareLoggerExtensions.cs b/src/Microsoft.AspNetCore.Routing/Logging/RouterMiddlewareLoggerExtensions.cs index 35f05272cd..77fba27317 100644 --- a/src/Microsoft.AspNetCore.Routing/Logging/RouterMiddlewareLoggerExtensions.cs +++ b/src/Microsoft.AspNetCore.Routing/Logging/RouterMiddlewareLoggerExtensions.cs @@ -15,7 +15,7 @@ namespace Microsoft.AspNetCore.Routing.Logging _requestDidNotMatchRoutes = LoggerMessage.Define( LogLevel.Debug, 1, - "Request did not match any routes."); + "Request did not match any routes"); } public static void RequestDidNotMatchRoutes(this ILogger logger) diff --git a/src/Microsoft.AspNetCore.Routing/Logging/TreeRouterLoggerExtensions.cs b/src/Microsoft.AspNetCore.Routing/Logging/TreeRouterLoggerExtensions.cs index 3f6af8e5dc..825e9ef888 100644 --- a/src/Microsoft.AspNetCore.Routing/Logging/TreeRouterLoggerExtensions.cs +++ b/src/Microsoft.AspNetCore.Routing/Logging/TreeRouterLoggerExtensions.cs @@ -15,7 +15,7 @@ namespace Microsoft.AspNetCore.Routing.Logging _matchedRoute = LoggerMessage.Define( LogLevel.Debug, 1, - "Request successfully matched the route with name '{RouteName}' and template '{RouteTemplate}'."); + "Request successfully matched the route with name '{RouteName}' and template '{RouteTemplate}'"); } public static void MatchedRoute( diff --git a/src/Microsoft.AspNetCore.Routing/Matching/DfaMatcher.cs b/src/Microsoft.AspNetCore.Routing/Matching/DfaMatcher.cs index 212acaf1b5..da0f799129 100644 --- a/src/Microsoft.AspNetCore.Routing/Matching/DfaMatcher.cs +++ b/src/Microsoft.AspNetCore.Routing/Matching/DfaMatcher.cs @@ -6,17 +6,20 @@ using System.Collections.Generic; using System.Threading.Tasks; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Routing.Patterns; +using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Routing.Matching { internal sealed class DfaMatcher : Matcher { + private readonly ILogger _logger; private readonly EndpointSelector _selector; private readonly DfaState[] _states; private readonly int _maxSegmentCount; - public DfaMatcher(EndpointSelector selector, DfaState[] states, int maxSegmentCount) + public DfaMatcher(ILogger logger, EndpointSelector selector, DfaState[] states, int maxSegmentCount) { + _logger = logger; _selector = selector; _states = states; _maxSegmentCount = maxSegmentCount; @@ -34,6 +37,9 @@ namespace Microsoft.AspNetCore.Routing.Matching throw new ArgumentNullException(nameof(context)); } + // All of the logging we do here is at level debug, so we can get away with doing a single check. + var log = _logger.IsEnabled(LogLevel.Debug); + // The sequence of actions we take is optimized to avoid doing expensive work // like creating substrings, creating route value dictionaries, and calling // into policies like versioning. @@ -49,9 +55,19 @@ namespace Microsoft.AspNetCore.Routing.Matching var candidates = FindCandidateSet(httpContext, path, segments); if (candidates.Length == 0) { + if (log) + { + Logger.CandidatesNotFound(_logger, path); + } + return Task.CompletedTask; } + if (log) + { + Logger.CandidatesFound(_logger, path, candidates); + } + // At this point we have a candidate set, defined as a list of endpoints in // priority order. // @@ -117,21 +133,34 @@ namespace Microsoft.AspNetCore.Routing.Matching // Now that we have the route values, we need to process complex segments. // Complex segments go through an old API that requires a fully-materialized // route value dictionary. + var isMatch = true; if ((flags & Candidate.CandidateFlags.HasComplexSegments) != 0) { - if (!ProcessComplexSegments(candidate.ComplexSegments, path, segments, values)) + if (!ProcessComplexSegments(candidate.Endpoint, candidate.ComplexSegments, path, segments, values)) { candidateSet.SetValidity(i, false); - continue; + isMatch = false; } } if ((flags & Candidate.CandidateFlags.HasConstraints) != 0) { - if (!ProcessConstraints(candidate.Constraints, httpContext, values)) + if (!ProcessConstraints(candidate.Endpoint, candidate.Constraints, httpContext, values)) { candidateSet.SetValidity(i, false); - continue; + isMatch = false; + } + } + + if (log) + { + if (isMatch) + { + Logger.CandidateValid(_logger, path, candidate.Endpoint); + } + else + { + Logger.CandidateNotValid(_logger, path, candidate.Endpoint); } } } @@ -202,6 +231,7 @@ namespace Microsoft.AspNetCore.Routing.Matching } private bool ProcessComplexSegments( + Endpoint endpoint, (RoutePatternPathSegment pathSegment, int segmentIndex)[] complexSegments, string path, ReadOnlySpan segments, @@ -209,10 +239,12 @@ namespace Microsoft.AspNetCore.Routing.Matching { for (var i = 0; i < complexSegments.Length; i++) { - var segment = segments[complexSegments[i].segmentIndex]; + (var complexSegment, var segmentIndex) = complexSegments[i]; + var segment = segments[segmentIndex]; var text = path.Substring(segment.Start, segment.Length); - if (!RoutePatternMatcher.MatchComplexSegment(complexSegments[i].pathSegment, text, values)) + if (!RoutePatternMatcher.MatchComplexSegment(complexSegment, text, values)) { + Logger.CandidateRejectedByComplexSegment(_logger, path, endpoint, complexSegment); return false; } } @@ -221,6 +253,7 @@ namespace Microsoft.AspNetCore.Routing.Matching } private bool ProcessConstraints( + Endpoint endpoint, KeyValuePair[] constraints, HttpContext httpContext, RouteValueDictionary values) @@ -230,11 +263,112 @@ namespace Microsoft.AspNetCore.Routing.Matching var constraint = constraints[i]; if (!constraint.Value.Match(httpContext, NullRouter.Instance, constraint.Key, values, RouteDirection.IncomingRequest)) { + Logger.CandidateRejectedByConstraint(_logger, httpContext.Request.Path, endpoint, constraint.Key, constraint.Value, values[constraint.Key]); return false; } } return true; } + + internal static class EventIds + { + public static readonly EventId CandidatesNotFound = new EventId(1000, "CandidatesNotFound"); + public static readonly EventId CandidatesFound = new EventId(1001, "CandidatesFound"); + + public static readonly EventId CandidateRejectedByComplexSegment = new EventId(1002, "CandidateRejectedByComplexSegment"); + public static readonly EventId CandidateRejectedByConstraint = new EventId(1003, "CandidateRejectedByConstraint"); + + public static readonly EventId CandidateNotValid = new EventId(1004, "CandiateNotValid"); + public static readonly EventId CandidateValid = new EventId(1005, "CandiateValid"); + } + + private static class Logger + { + private static readonly Action _candidatesNotFound = LoggerMessage.Define( + LogLevel.Debug, + EventIds.CandidatesNotFound, + "No candidates found for the request path '{Path}'"); + + private static readonly Action _candidatesFound = LoggerMessage.Define( + LogLevel.Debug, + EventIds.CandidatesFound, + "{CandidateCount} candidate(s) found for the request path '{Path}'"); + + private static readonly Action _candidateRejectedByComplexSegment = LoggerMessage.Define( + LogLevel.Debug, + EventIds.CandidateRejectedByComplexSegment, + "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' was rejected by complex segment '{Segment}' for the request path '{Path}'"); + + private static readonly Action _candidateRejectedByConstraint = LoggerMessage.Define( + LogLevel.Debug, + EventIds.CandidateRejectedByConstraint, + "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' was rejected by constraint '{ConstraintName}':'{Constraint}' with value '{RouteValue}' for the request path '{Path}'"); + + private static readonly Action _candidateNotValid = LoggerMessage.Define( + LogLevel.Debug, + EventIds.CandidateNotValid, + "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' is not valid for the request path '{Path}'"); + + private static readonly Action _candidateValid = LoggerMessage.Define( + LogLevel.Debug, + EventIds.CandidateValid, + "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' is valid for the request path '{Path}'"); + + public static void CandidatesNotFound(ILogger logger, string path) + { + _candidatesNotFound(logger, path, null); + } + + public static void CandidatesFound(ILogger logger, string path, Candidate[] candidates) + { + _candidatesFound(logger, candidates.Length, path, null); + } + + public static void CandidateRejectedByComplexSegment(ILogger logger, string path, Endpoint endpoint, RoutePatternPathSegment segment) + { + // This should return a real pattern since we're processing complex segments.... but just in case. + if (logger.IsEnabled(LogLevel.Debug)) + { + var routePattern = GetRoutePattern(endpoint); + _candidateRejectedByComplexSegment(logger, endpoint.DisplayName, routePattern, segment.DebuggerToString(), path, null); + } + } + + public static void CandidateRejectedByConstraint(ILogger logger, string path, Endpoint endpoint, string constraintName, IRouteConstraint constraint, object value) + { + // This should return a real pattern since we're processing constraints.... but just in case. + if (logger.IsEnabled(LogLevel.Debug)) + { + var routePattern = GetRoutePattern(endpoint); + _candidateRejectedByConstraint(logger, endpoint.DisplayName, routePattern, constraintName, constraint.ToString(), value, path, null); + } + } + + public static void CandidateNotValid(ILogger logger, string path, Endpoint endpoint) + { + // This can be the fallback value because it really might not be a route endpoint + if (logger.IsEnabled(LogLevel.Debug)) + { + var routePattern = GetRoutePattern(endpoint); + _candidateNotValid(logger, endpoint.DisplayName, routePattern, path, null); + } + } + + public static void CandidateValid(ILogger logger, string path, Endpoint endpoint) + { + // This can be the fallback value because it really might not be a route endpoint + if (logger.IsEnabled(LogLevel.Debug)) + { + var routePattern = GetRoutePattern(endpoint); + _candidateValid(logger, endpoint.DisplayName, routePattern, path, null); + } + } + + private static string GetRoutePattern(Endpoint endpoint) + { + return (endpoint as RouteEndpoint)?.RoutePattern?.RawText ?? "(none)"; + } + } } } diff --git a/src/Microsoft.AspNetCore.Routing/Matching/DfaMatcherBuilder.cs b/src/Microsoft.AspNetCore.Routing/Matching/DfaMatcherBuilder.cs index 28b5cdf353..bff708feea 100644 --- a/src/Microsoft.AspNetCore.Routing/Matching/DfaMatcherBuilder.cs +++ b/src/Microsoft.AspNetCore.Routing/Matching/DfaMatcherBuilder.cs @@ -6,6 +6,7 @@ using System.Collections.Generic; using System.Linq; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Routing.Patterns; +using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Routing.Matching { @@ -13,6 +14,7 @@ namespace Microsoft.AspNetCore.Routing.Matching { private readonly List _endpoints = new List(); + private readonly ILoggerFactory _loggerFactory; private readonly ParameterPolicyFactory _parameterPolicyFactory; private readonly EndpointSelector _selector; private readonly MatcherPolicy[] _policies; @@ -29,10 +31,12 @@ namespace Microsoft.AspNetCore.Routing.Matching private int _stateIndex; public DfaMatcherBuilder( + ILoggerFactory loggerFactory, ParameterPolicyFactory parameterPolicyFactory, EndpointSelector selector, IEnumerable policies) { + _loggerFactory = loggerFactory; _parameterPolicyFactory = parameterPolicyFactory; _selector = selector; _policies = policies.OrderBy(p => p.Order).ToArray(); @@ -304,7 +308,7 @@ namespace Microsoft.AspNetCore.Routing.Matching JumpTableBuilder.Build(exitDestination, exitDestination, null), null); - return new DfaMatcher(_selector, states, maxSegmentCount); + return new DfaMatcher(_loggerFactory.CreateLogger(), _selector, states, maxSegmentCount); } private int AddNode( diff --git a/test/Microsoft.AspNetCore.Routing.Tests/ConstraintMatcherTest.cs b/test/Microsoft.AspNetCore.Routing.Tests/ConstraintMatcherTest.cs index 4d9b436e81..59194e3a0b 100644 --- a/test/Microsoft.AspNetCore.Routing.Tests/ConstraintMatcherTest.cs +++ b/test/Microsoft.AspNetCore.Routing.Tests/ConstraintMatcherTest.cs @@ -56,7 +56,7 @@ namespace Microsoft.AspNetCore.Routing }; var sink = SetUpMatch(constraints, loggerEnabled: true); var expectedMessage = "Route value 'value' with key 'b' did not match the constraint " + - $"'{typeof(FailConstraint).FullName}'."; + $"'{typeof(FailConstraint).FullName}'"; // Assert Assert.Empty(sink.Scopes); diff --git a/test/Microsoft.AspNetCore.Routing.Tests/EndpointRoutingMiddlewareTest.cs b/test/Microsoft.AspNetCore.Routing.Tests/EndpointRoutingMiddlewareTest.cs index a15d94e340..dad2fdf0ff 100644 --- a/test/Microsoft.AspNetCore.Routing.Tests/EndpointRoutingMiddlewareTest.cs +++ b/test/Microsoft.AspNetCore.Routing.Tests/EndpointRoutingMiddlewareTest.cs @@ -36,7 +36,7 @@ namespace Microsoft.AspNetCore.Routing public async Task Invoke_OnCall_WritesToConfiguredLogger() { // Arrange - var expectedMessage = "Request matched endpoint 'Test endpoint'."; + var expectedMessage = "Request matched endpoint 'Test endpoint'"; var sink = new TestSink( TestSink.EnableWithTypeName, diff --git a/test/Microsoft.AspNetCore.Routing.Tests/Matching/CandidateSetTest.cs b/test/Microsoft.AspNetCore.Routing.Tests/Matching/CandidateSetTest.cs index b94923df3c..470103e283 100644 --- a/test/Microsoft.AspNetCore.Routing.Tests/Matching/CandidateSetTest.cs +++ b/test/Microsoft.AspNetCore.Routing.Tests/Matching/CandidateSetTest.cs @@ -5,6 +5,7 @@ using System; using System.Linq; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Routing.Patterns; +using Microsoft.Extensions.Logging.Abstractions; using Moq; using Xunit; @@ -117,6 +118,7 @@ namespace Microsoft.AspNetCore.Routing.Matching { var dataSource = new CompositeEndpointDataSource(Array.Empty()); return new DfaMatcherBuilder( + NullLoggerFactory.Instance, Mock.Of(), Mock.Of(), policies); diff --git a/test/Microsoft.AspNetCore.Routing.Tests/Matching/DfaMatcherBuilderTest.cs b/test/Microsoft.AspNetCore.Routing.Tests/Matching/DfaMatcherBuilderTest.cs index 10c0aec62e..e2eec83cb0 100644 --- a/test/Microsoft.AspNetCore.Routing.Tests/Matching/DfaMatcherBuilderTest.cs +++ b/test/Microsoft.AspNetCore.Routing.Tests/Matching/DfaMatcherBuilderTest.cs @@ -7,6 +7,7 @@ using System.Linq; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Routing.Constraints; using Microsoft.AspNetCore.Routing.Patterns; +using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Options; using Moq; using Xunit; @@ -972,6 +973,7 @@ namespace Microsoft.AspNetCore.Routing.Matching { var dataSource = new CompositeEndpointDataSource(Array.Empty()); return new DfaMatcherBuilder( + NullLoggerFactory.Instance, new DefaultParameterPolicyFactory(Options.Create(new RouteOptions()), Mock.Of()), Mock.Of(), policies); diff --git a/test/Microsoft.AspNetCore.Routing.Tests/Matching/DfaMatcherTest.cs b/test/Microsoft.AspNetCore.Routing.Tests/Matching/DfaMatcherTest.cs index 924a11b733..08e3b76570 100644 --- a/test/Microsoft.AspNetCore.Routing.Tests/Matching/DfaMatcherTest.cs +++ b/test/Microsoft.AspNetCore.Routing.Tests/Matching/DfaMatcherTest.cs @@ -7,6 +7,8 @@ using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Routing.Patterns; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Testing; using Moq; using Xunit; @@ -26,7 +28,7 @@ namespace Microsoft.AspNetCore.Routing.Matching template); } - private Matcher CreateDfaMatcher(EndpointDataSource dataSource, EndpointSelector endpointSelector = null) + private Matcher CreateDfaMatcher(EndpointDataSource dataSource, EndpointSelector endpointSelector = null, ILoggerFactory loggerFactory = null) { var serviceCollection = new ServiceCollection() .AddLogging() @@ -38,6 +40,11 @@ namespace Microsoft.AspNetCore.Routing.Matching serviceCollection.AddSingleton(endpointSelector); } + if (loggerFactory != null) + { + serviceCollection.AddSingleton(loggerFactory); + } + var services = serviceCollection.BuildServiceProvider(); var factory = services.GetRequiredService(); @@ -76,14 +83,14 @@ namespace Microsoft.AspNetCore.Routing.Matching var matcher = CreateDfaMatcher(endpointDataSource); - var (httpContext, endpointFeature) = CreateContext(); + var (httpContext, context) = CreateContext(); httpContext.Request.Path = "/One"; // Act - await matcher.MatchAsync(httpContext, endpointFeature); + await matcher.MatchAsync(httpContext, context); // Assert - Assert.Null(endpointFeature.Endpoint); + Assert.Null(context.Endpoint); } [Fact] @@ -101,14 +108,14 @@ namespace Microsoft.AspNetCore.Routing.Matching var matcher = CreateDfaMatcher(endpointDataSource); - var (httpContext, endpointFeature) = CreateContext(); + var (httpContext, context) = CreateContext(); httpContext.Request.Path = "/Teams"; // Act - await matcher.MatchAsync(httpContext, endpointFeature); + await matcher.MatchAsync(httpContext, context); // Assert - Assert.Equal(lowerOrderEndpoint, endpointFeature.Endpoint); + Assert.Equal(lowerOrderEndpoint, context.Endpoint); } [Fact] @@ -147,14 +154,181 @@ namespace Microsoft.AspNetCore.Routing.Matching var matcher = CreateDfaMatcher(endpointDataSource, endpointSelector.Object); - var (httpContext, endpointFeature) = CreateContext(); + var (httpContext, context) = CreateContext(); httpContext.Request.Path = "/Teams"; // Act - await matcher.MatchAsync(httpContext, endpointFeature); + await matcher.MatchAsync(httpContext, context); // Assert - Assert.Equal(endpoint2, endpointFeature.Endpoint); + Assert.Equal(endpoint2, context.Endpoint); + } + + [Fact] + public async Task MatchAsync_NoCandidates_Logging() + { + // Arrange + var endpointDataSource = new DefaultEndpointDataSource(new List + { + CreateEndpoint("/{p:int}", 0) + }); + + var sink = new TestSink(); + var matcher = CreateDfaMatcher(endpointDataSource, loggerFactory: new TestLoggerFactory(sink, enabled: true)); + + var (httpContext, context) = CreateContext(); + httpContext.Request.Path = "/"; + + // Act + await matcher.MatchAsync(httpContext, context); + + // Assert + Assert.Null(context.Endpoint); + + Assert.Collection( + sink.Writes, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidatesNotFound, log.EventId); + Assert.Equal("No candidates found for the request path '/'", log.Message); + }); + } + + [Fact] + public async Task MatchAsync_ConstraintRejectsEndpoint_Logging() + { + // Arrange + var endpointDataSource = new DefaultEndpointDataSource(new List + { + CreateEndpoint("/{p:int}", 0) + }); + + var sink = new TestSink(); + var matcher = CreateDfaMatcher(endpointDataSource, loggerFactory: new TestLoggerFactory(sink, enabled: true)); + + var (httpContext, context) = CreateContext(); + httpContext.Request.Path = "/One"; + + // Act + await matcher.MatchAsync(httpContext, context); + + // Assert + Assert.Null(context.Endpoint); + + Assert.Collection( + sink.Writes, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidatesFound, log.EventId); + Assert.Equal("1 candidate(s) found for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateRejectedByConstraint, log.EventId); + Assert.Equal("Endpoint '/{p:int}' with route pattern '/{p:int}' was rejected by constraint 'p':'Microsoft.AspNetCore.Routing.Constraints.IntRouteConstraint' with value 'One' for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateNotValid, log.EventId); + Assert.Equal("Endpoint '/{p:int}' with route pattern '/{p:int}' is not valid for the request path '/One'", log.Message); + }); + } + + [Fact] + public async Task MatchAsync_ComplexSegmentRejectsEndpoint_Logging() + { + // Arrange + var endpointDataSource = new DefaultEndpointDataSource(new List + { + CreateEndpoint("/x-{id}-y", 0) + }); + + var sink = new TestSink(); + var matcher = CreateDfaMatcher(endpointDataSource, loggerFactory: new TestLoggerFactory(sink, enabled: true)); + + var (httpContext, context) = CreateContext(); + httpContext.Request.Path = "/One"; + + // Act + await matcher.MatchAsync(httpContext, context); + + // Assert + Assert.Null(context.Endpoint); + + Assert.Collection( + sink.Writes, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidatesFound, log.EventId); + Assert.Equal("1 candidate(s) found for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateRejectedByComplexSegment, log.EventId); + Assert.Equal("Endpoint '/x-{id}-y' with route pattern '/x-{id}-y' was rejected by complex segment 'x-{id}-y' for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateNotValid, log.EventId); + Assert.Equal("Endpoint '/x-{id}-y' with route pattern '/x-{id}-y' is not valid for the request path '/One'", log.Message); + }); + } + + [Fact] + public async Task MatchAsync_MultipleCandidates_Logging() + { + // Arrange + var endpointDataSource = new DefaultEndpointDataSource(new List + { + CreateEndpoint("/One", 0), + CreateEndpoint("/{p:int}", 0), + CreateEndpoint("/x-{id}-y", 0), + }); + + var sink = new TestSink(); + var matcher = CreateDfaMatcher(endpointDataSource, loggerFactory: new TestLoggerFactory(sink, enabled: true)); + + var (httpContext, context) = CreateContext(); + httpContext.Request.Path = "/One"; + + // Act + await matcher.MatchAsync(httpContext, context); + + // Assert + Assert.Same(endpointDataSource.Endpoints[0], context.Endpoint); + + Assert.Collection( + sink.Writes, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidatesFound, log.EventId); + Assert.Equal("3 candidate(s) found for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateValid, log.EventId); + Assert.Equal("Endpoint '/One' with route pattern '/One' is valid for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateRejectedByConstraint, log.EventId); + Assert.Equal("Endpoint '/{p:int}' with route pattern '/{p:int}' was rejected by constraint 'p':'Microsoft.AspNetCore.Routing.Constraints.IntRouteConstraint' with value 'One' for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateNotValid, log.EventId); + Assert.Equal("Endpoint '/{p:int}' with route pattern '/{p:int}' is not valid for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateRejectedByComplexSegment, log.EventId); + Assert.Equal("Endpoint '/x-{id}-y' with route pattern '/x-{id}-y' was rejected by complex segment 'x-{id}-y' for the request path '/One'", log.Message); + }, + (log) => + { + Assert.Equal(DfaMatcher.EventIds.CandidateNotValid, log.EventId); + Assert.Equal("Endpoint '/x-{id}-y' with route pattern '/x-{id}-y' is not valid for the request path '/One'", log.Message); + }); } private (HttpContext httpContext, EndpointSelectorContext context) CreateContext() diff --git a/test/Microsoft.AspNetCore.Routing.Tests/RouterMiddlewareTest.cs b/test/Microsoft.AspNetCore.Routing.Tests/RouterMiddlewareTest.cs index 7f6bd73963..3df8f6ad48 100644 --- a/test/Microsoft.AspNetCore.Routing.Tests/RouterMiddlewareTest.cs +++ b/test/Microsoft.AspNetCore.Routing.Tests/RouterMiddlewareTest.cs @@ -16,7 +16,7 @@ namespace Microsoft.AspNetCore.Routing public async Task Invoke_LogsCorrectValues_WhenNotHandled() { // Arrange - var expectedMessage = "Request did not match any routes."; + var expectedMessage = "Request did not match any routes"; var isHandled = false; var sink = new TestSink(