Write log message for matched fallback routes (#47798)

Co-authored-by: Chris Ross <[email protected]>

Author: JamesNK

src/Http/Routing/src/Builder/FallbackEndpointRouteBuilderExtensions.cs

@@ -77,6 +77,7 @@ public static IEndpointConventionBuilder MapFallback(
         var conventionBuilder = endpoints.Map(pattern, requestDelegate);
         conventionBuilder.WithDisplayName("Fallback " + pattern);
         conventionBuilder.Add(b => ((RouteEndpointBuilder)b).Order = int.MaxValue);
+        conventionBuilder.WithMetadata(FallbackMetadata.Instance);
         return conventionBuilder;
     }
 }

src/Http/Routing/src/EndpointRoutingMiddleware.cs

@@ -109,6 +109,12 @@ private Task SetRoutingAndContinue(HttpContext httpContext)
 
             Log.MatchSuccess(_logger, endpoint);
 
+            if (_logger.IsEnabled(LogLevel.Debug)
+                && endpoint.Metadata.GetMetadata<FallbackMetadata>() is not null)
+            {
+                Log.FallbackMatch(_logger, endpoint);
+            }
+
             var shortCircuitMetadata = endpoint.Metadata.GetMetadata<ShortCircuitMetadata>();
             if (shortCircuitMetadata is not null)
             {
@@ -283,5 +289,8 @@ public static void MatchSkipped(ILogger logger, Endpoint endpoint)
 
         [LoggerMessage(6, LogLevel.Information, "The endpoint '{EndpointName}' is being short circuited without running additional middleware or producing a response.", EventName = "ShortCircuitedEndpoint")]
         public static partial void ShortCircuitedEndpoint(ILogger logger, Endpoint endpointName);
+
+        [LoggerMessage(7, LogLevel.Debug, "Matched endpoint '{EndpointName}' is a fallback endpoint.", EventName = "FallbackMatch", SkipEnabledCheck = true)]
+        public static partial void FallbackMatch(ILogger logger, Endpoint endpointName);
     }
 }

src/Http/Routing/src/FallbackMetadata.cs

@@ -0,0 +1,13 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+
+namespace Microsoft.AspNetCore.Routing;
+
+internal sealed class FallbackMetadata
+{
+    public static readonly FallbackMetadata Instance = new FallbackMetadata();
+
+    private FallbackMetadata()
+    {
+    }
+}

src/Http/Routing/src/RouteEndpointDataSource.cs

@@ -127,7 +127,7 @@ private RouteEndpointBuilder CreateRouteEndpointBuilder(
         // The Map methods don't support customizing the order apart from using int.MaxValue to give MapFallback the lowest priority.
         // Otherwise, we always use the default of 0 unless a convention changes it later.
         var order = isFallback ? int.MaxValue : 0;
-        var displayName = pattern.RawText ?? pattern.DebuggerToString();
+        var displayName = pattern.DebuggerToString();
 
         // Don't include the method name for non-route-handlers because the name is just "Invoke" when built from
         // ApplicationBuilder.Build(). This was observed in MapSignalRTests and is not very useful. Maybe if we come up
@@ -173,6 +173,11 @@ private RouteEndpointBuilder CreateRouteEndpointBuilder(
             ApplicationServices = _applicationServices,
         };
 
+        if (isFallback)
+        {
+            builder.Metadata.Add(FallbackMetadata.Instance);
+        }
+
         if (isRouteHandler)
         {
             builder.Metadata.Add(handler.Method);

src/Http/Routing/test/UnitTests/Builder/FallbackEndpointRouteBuilderExtensionsTest.cs

@@ -0,0 +1,53 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+
+#nullable enable
+
+using Microsoft.AspNetCore.Http;
+using Microsoft.AspNetCore.Routing;
+
+namespace Microsoft.AspNetCore.Builder;
+
+public class FallbackEndpointRouteBuilderExtensionsTest
+{
+    private EndpointDataSource GetBuilderEndpointDataSource(IEndpointRouteBuilder endpointRouteBuilder) =>
+        Assert.Single(endpointRouteBuilder.DataSources);
+
+    [Fact]
+    public void MapFallback_AddFallbackMetadata()
+    {
+        var builder = new DefaultEndpointRouteBuilder(new ApplicationBuilder(EmptyServiceProvider.Instance));
+
+        RequestDelegate initialRequestDelegate = static (context) => Task.CompletedTask;
+
+        builder.MapFallback(initialRequestDelegate);
+
+        var dataSource = GetBuilderEndpointDataSource(builder);
+        var endpoint = Assert.Single(dataSource.Endpoints);
+
+        Assert.Contains(FallbackMetadata.Instance, endpoint.Metadata);
+        Assert.Equal(int.MaxValue, ((RouteEndpoint)endpoint).Order);
+    }
+
+    [Fact]
+    public void MapFallback_Pattern_AddFallbackMetadata()
+    {
+        var builder = new DefaultEndpointRouteBuilder(new ApplicationBuilder(EmptyServiceProvider.Instance));
+
+        RequestDelegate initialRequestDelegate = static (context) => Task.CompletedTask;
+
+        builder.MapFallback("/", initialRequestDelegate);
+
+        var dataSource = GetBuilderEndpointDataSource(builder);
+        var endpoint = Assert.Single(dataSource.Endpoints);
+
+        Assert.Contains(FallbackMetadata.Instance, endpoint.Metadata);
+        Assert.Equal(int.MaxValue, ((RouteEndpoint)endpoint).Order);
+    }
+
+    private sealed class EmptyServiceProvider : IServiceProvider
+    {
+        public static EmptyServiceProvider Instance { get; } = new EmptyServiceProvider();
+        public object? GetService(Type serviceType) => null;
+    }
+}

src/Http/Routing/test/UnitTests/Builder/RouteHandlerEndpointRouteBuilderExtensionsTest.cs

@@ -765,6 +765,7 @@ public void MapFallbackWithoutPath_BuildsEndpointWithLowestRouteOrder()
         Assert.Single(routeEndpointBuilder.RoutePattern.Parameters);
         Assert.True(routeEndpointBuilder.RoutePattern.Parameters[0].IsCatchAll);
         Assert.Equal(int.MaxValue, routeEndpointBuilder.Order);
+        Assert.Contains(FallbackMetadata.Instance, routeEndpointBuilder.Metadata);
     }
 
     [Fact]

src/Http/Routing/test/UnitTests/EndpointRoutingMiddlewareTest.cs

@@ -58,9 +58,7 @@ public async Task Invoke_OnCall_WritesToConfiguredLogger()
         var expectedMessage = "Request matched endpoint 'Test endpoint'";
         bool eventFired = false;
 
-        var sink = new TestSink(
-            TestSink.EnableWithTypeName<EndpointRoutingMiddleware>,
-            TestSink.EnableWithTypeName<EndpointRoutingMiddleware>);
+        var sink = new TestSink(TestSink.EnableWithTypeName<EndpointRoutingMiddleware>);
         var loggerFactory = new TestLoggerFactory(sink, enabled: true);
         var listener = new DiagnosticListener("TestListener");
 
@@ -224,6 +222,46 @@ public async Task ThrowIfSecurityMetadataPresent(int? statusCode, bool hasAuthMe
         await Assert.ThrowsAsync<InvalidOperationException>(() => middleware.Invoke(httpContext));
     }
 
+    [Theory]
+    [InlineData(true)]
+    [InlineData(false)]
+    public async Task Invoke_CheckForFallbackMetadata_LogIfPresent(bool hasFallbackMetadata)
+    {
+        // Arrange
+        var sink = new TestSink(TestSink.EnableWithTypeName<EndpointRoutingMiddleware>);
+        var loggerFactory = new TestLoggerFactory(sink, enabled: true);
+        var logger = new Logger<EndpointRoutingMiddleware>(loggerFactory);
+
+        var metadata = new List<object>();
+        if (hasFallbackMetadata)
+        {
+            metadata.Add(FallbackMetadata.Instance);
+        }
+
+        var httpContext = CreateHttpContext();
+
+        var middleware = CreateMiddleware(
+            logger: logger,
+            matcherFactory: new TestMatcherFactory(isHandled: true, setEndpointCallback: c =>
+            {
+                c.SetEndpoint(new Endpoint(c => Task.CompletedTask, new EndpointMetadataCollection(metadata), "myapp"));
+            }));
+
+        // Act
+        await middleware.Invoke(httpContext);
+
+        // Assert
+        if (hasFallbackMetadata)
+        {
+            var write = Assert.Single(sink.Writes.Where(w => w.EventId.Name == "FallbackMatch"));
+            Assert.Equal("Matched endpoint 'myapp' is a fallback endpoint.", write.Message);
+        }
+        else
+        {
+            Assert.DoesNotContain(sink.Writes, w => w.EventId.Name == "FallbackMatch");
+        }
+    }
+
     private HttpContext CreateHttpContext()
     {
         var httpContext = new DefaultHttpContext
@@ -235,7 +273,7 @@ private HttpContext CreateHttpContext()
     }
 
     private EndpointRoutingMiddleware CreateMiddleware(
-        Logger<EndpointRoutingMiddleware> logger = null,
+        ILogger<EndpointRoutingMiddleware> logger = null,
         MatcherFactory matcherFactory = null,
         DiagnosticListener listener = null,
         RequestDelegate next = null)

src/Http/Routing/test/UnitTests/TestObjects/TestMatcher.cs

@@ -9,18 +9,25 @@ namespace Microsoft.AspNetCore.Routing.TestObjects;
 internal class TestMatcher : Matcher
 {
     private readonly bool _isHandled;
+    private readonly Action<HttpContext> _setEndpointCallback;
 
-    public TestMatcher(bool isHandled)
+    public TestMatcher(bool isHandled, Action<HttpContext> setEndpointCallback = null)
     {
         _isHandled = isHandled;
+
+        setEndpointCallback ??= static c =>
+            {
+                c.Request.RouteValues = new RouteValueDictionary(new { controller = "Home", action = "Index" });
+                c.SetEndpoint(new Endpoint(TestConstants.EmptyRequestDelegate, EndpointMetadataCollection.Empty, "Test endpoint"));
+            };
+        _setEndpointCallback = setEndpointCallback;
     }
 
     public override Task MatchAsync(HttpContext httpContext)
     {
         if (_isHandled)
         {
-            httpContext.Request.RouteValues = new RouteValueDictionary(new { controller = "Home", action = "Index" });
-            httpContext.SetEndpoint(new Endpoint(TestConstants.EmptyRequestDelegate, EndpointMetadataCollection.Empty, "Test endpoint"));
+            _setEndpointCallback(httpContext);
         }
 
         return Task.CompletedTask;

src/Http/Routing/test/UnitTests/TestObjects/TestMatcherFactory.cs

@@ -12,15 +12,17 @@ namespace Microsoft.AspNetCore.Routing.TestObjects;
 internal class TestMatcherFactory : MatcherFactory
 {
     private readonly bool _isHandled;
+    private readonly Action<HttpContext> _setEndpointCallback;
 
-    public TestMatcherFactory(bool isHandled)
+    public TestMatcherFactory(bool isHandled, Action<HttpContext> setEndpointCallback = null)
     {
         _isHandled = isHandled;
+        _setEndpointCallback = setEndpointCallback;
     }
 
     public override Matcher CreateMatcher(EndpointDataSource dataSource)
     {
-        return new TestMatcher(_isHandled);
+        return new TestMatcher(_isHandled, _setEndpointCallback);
     }
 }