Selectors initialization and DispatcherBase logging (#451)

src/Microsoft.AspNetCore.Dispatcher.Abstractions/Endpoint.cs

@@ -6,7 +6,7 @@ using System.Diagnostics;
 
 namespace Microsoft.AspNetCore.Dispatcher
 {
-    [DebuggerDisplay("{DisplayName,nq}")]
+    [DebuggerDisplay("{GetType().Name} - '{DisplayName,nq}'")]
     public abstract class Endpoint
     {
         public abstract string DisplayName { get; }

src/Microsoft.AspNetCore.Dispatcher/AmbiguousEndpointException.cs

@@ -0,0 +1,25 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System;
+using System.Runtime.Serialization;
+
+namespace Microsoft.AspNetCore.Dispatcher
+{
+    /// <summary>
+    /// An exception which indicates multiple matches in endpoint selection.
+    /// </summary>
+    [Serializable]
+    public class AmbiguousEndpointException : Exception
+    {
+        public AmbiguousEndpointException(string message)
+            : base(message)
+        {
+        }
+
+        protected AmbiguousEndpointException(SerializationInfo info, StreamingContext context)
+            : base(info, context)
+        {
+        }
+    }
+}

src/Microsoft.AspNetCore.Dispatcher/DispatcherBase.cs

@@ -4,9 +4,12 @@
 using System;
 using System.Collections.Generic;
 using System.Linq;
+using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.FileProviders;
+using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Primitives;
 
 namespace Microsoft.AspNetCore.Dispatcher
@@ -17,6 +20,21 @@ namespace Microsoft.AspNetCore.Dispatcher
         private List<Endpoint> _endpoints;
         private List<EndpointSelector> _endpointSelectors;
 
+        private object _initialize;
+        private bool _selectorsInitialized;
+        private readonly Func<object> _initializer;
+        private object _lock;
+
+        private bool _servicesInitialized;
+
+        public DispatcherBase()
+        {
+            _lock = new object();
+            _initializer = InitializeSelectors;
+        }
+
+        protected ILogger Logger { get; private set; }
+
         public virtual IList<Address> Addresses
         {
             get
@@ -81,6 +99,8 @@ namespace Microsoft.AspNetCore.Dispatcher
                 throw new ArgumentNullException(nameof(httpContext));
             }
 
+            EnsureServicesInitialized(httpContext);
+
             var feature = httpContext.Features.Get<IDispatcherFeature>();
             if (await TryMatchAsync(httpContext))
             {
@@ -117,20 +137,64 @@ namespace Microsoft.AspNetCore.Dispatcher
                 throw new ArgumentNullException(nameof(selectors));
             }
 
+            LazyInitializer.EnsureInitialized(ref _initialize, ref _selectorsInitialized, ref _lock, _initializer);
+
             var selectorContext = new EndpointSelectorContext(httpContext, endpoints.ToList(), selectors.ToList());
             await selectorContext.InvokeNextAsync();
 
             switch (selectorContext.Endpoints.Count)
             {
                 case 0:
+                    Logger.NoEndpointsMatched(httpContext.Request.Path);
                     return null;
 
                 case 1:
+                    Logger.EndpointMatched(selectorContext.Endpoints[0].DisplayName);
                     return selectorContext.Endpoints[0];
 
                 default:
-                    throw new InvalidOperationException("Ambiguous bro!");
+                    var endpointNames = string.Join(
+                            Environment.NewLine,
+                            selectorContext.Endpoints.Select(a => a.DisplayName));
 
+                    Logger.AmbiguousEndpoints(endpointNames);
+
+                    var message = Resources.FormatAmbiguousEndpoints(
+                        Environment.NewLine,
+                        endpointNames);
+
+                    throw new AmbiguousEndpointException(message);
+            }
+        }
+
+        private object InitializeSelectors()
+        {
+            foreach (var selector in Selectors)
+            {
+                selector.Initialize(this);
+            }
+
+            return null;
+        }
+
+        protected void EnsureServicesInitialized(HttpContext httpContext)
+        {
+            if (Volatile.Read(ref _servicesInitialized))
+            {
+                return;
+            }
+
+            EnsureServicesInitializedSlow(httpContext);
+        }
+
+        private void EnsureServicesInitializedSlow(HttpContext httpContext)
+        {
+            lock (_lock)
+            {
+                if (!Volatile.Read(ref _servicesInitialized))
+                {
+                    Logger = httpContext.RequestServices.GetRequiredService<ILoggerFactory>().CreateLogger(GetType());
+                }
             }
         }
     }

src/Microsoft.AspNetCore.Dispatcher/DispatcherLoggerExtensions.cs

@@ -0,0 +1,44 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System;
+using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
+
+namespace Microsoft.AspNetCore.Dispatcher
+{
+    internal static class DispatcherLoggerExtensions
+    {
+        // Too many matches
+        private static readonly Action<ILogger, string, Exception> _ambiguousEndpoints = LoggerMessage.Define<string>(
+            LogLevel.Error,
+            new EventId(1, "AmbiguousEndpoints"),
+            "Request matched multiple endpoints resulting in ambiguity. Matching endpoints: {AmbiguousEndpoints}");
+
+        // Unique match found
+        private static readonly Action<ILogger, string, Exception> _endpointMatched = LoggerMessage.Define<string>(
+            LogLevel.Information,
+            new EventId(1, "EndpointMatched"),
+            "Request matched endpoint: {endpointName}");
+
+        private static readonly Action<ILogger, PathString, Exception> _noEndpointsMatched = LoggerMessage.Define<PathString>(
+            LogLevel.Debug,
+            new EventId(2, "NoEndpointsMatched"),
+            "No endpoints matched the current request path: {PathString}");
+
+        public static void AmbiguousEndpoints(this ILogger logger, string ambiguousEndpoints)
+        {
+            _ambiguousEndpoints(logger, ambiguousEndpoints, null);
+        }
+
+        public static void EndpointMatched(this ILogger logger, string endpointName)
+        {
+            _endpointMatched(logger, endpointName ?? "Unnamed endpoint", null);
+        }
+
+        public static void NoEndpointsMatched(this ILogger logger, PathString pathString)
+        {
+            _noEndpointsMatched(logger, pathString, null);
+        }
+    }
+}

src/Microsoft.AspNetCore.Dispatcher/EndpointSelector.cs

@@ -8,5 +8,9 @@ namespace Microsoft.AspNetCore.Dispatcher
     public abstract class EndpointSelector
     {
         public abstract Task SelectAsync(EndpointSelectorContext context);
+
+        public virtual void Initialize(IEndpointCollectionProvider endpointProvider)
+        {
+        }
     }
 }

src/Microsoft.AspNetCore.Dispatcher/Microsoft.AspNetCore.Dispatcher.csproj

@@ -15,6 +15,7 @@
     <PackageReference Include="Microsoft.AspNetCore.Hosting.Abstractions" />
     <PackageReference Include="Microsoft.AspNetCore.Http.Extensions" />
     <PackageReference Include="Microsoft.Extensions.DependencyInjection.Abstractions" />
+    <PackageReference Include="Microsoft.Extensions.HashCodeCombiner.Sources" PrivateAssets="All" />
     <PackageReference Include="Microsoft.Extensions.Options" />
   </ItemGroup>
 

src/Microsoft.AspNetCore.Dispatcher/Properties/Resources.Designer.cs

@@ -0,0 +1,44 @@
+// <auto-generated />
+namespace Microsoft.AspNetCore.Dispatcher
+{
+    using System.Globalization;
+    using System.Reflection;
+    using System.Resources;
+
+    internal static class Resources
+    {
+        private static readonly ResourceManager _resourceManager
+            = new ResourceManager("Microsoft.AspNetCore.Dispatcher.Resources", typeof(Resources).GetTypeInfo().Assembly);
+
+        /// <summary>
+        /// Multiple endpoints matched. The following endpoints matched the request:{0}{0}{1}
+        /// </summary>
+        internal static string AmbiguousEndpoints
+        {
+            get => GetString("AmbiguousEndpoints");
+        }
+
+        /// <summary>
+        /// Multiple endpoints matched. The following endpoints matched the request:{0}{0}{1}
+        /// </summary>
+        internal static string FormatAmbiguousEndpoints(object p0, object p1)
+            => string.Format(CultureInfo.CurrentCulture, GetString("AmbiguousEndpoints"), p0, p1);
+
+        private static string GetString(string name, params string[] formatterNames)
+        {
+            var value = _resourceManager.GetString(name);
+
+            System.Diagnostics.Debug.Assert(value != null);
+
+            if (formatterNames != null)
+            {
+                for (var i = 0; i < formatterNames.Length; i++)
+                {
+                    value = value.Replace("{" + formatterNames[i] + "}", "{" + i + "}");
+                }
+            }
+
+            return value;
+        }
+    }
+}

src/Microsoft.AspNetCore.Dispatcher/Resources.resx

@@ -0,0 +1,124 @@
+<?xml version="1.0" encoding="utf-8"?>
+<root>
+  <!-- 
+    Microsoft ResX Schema 
+    
+    Version 2.0
+    
+    The primary goals of this format is to allow a simple XML format 
+    that is mostly human readable. The generation and parsing of the 
+    various data types are done through the TypeConverter classes 
+    associated with the data types.
+    
+    Example:
+    
+    ... ado.net/XML headers & schema ...
+    <resheader name="resmimetype">text/microsoft-resx</resheader>
+    <resheader name="version">2.0</resheader>
+    <resheader name="reader">System.Resources.ResXResourceReader, System.Windows.Forms, ...</resheader>
+    <resheader name="writer">System.Resources.ResXResourceWriter, System.Windows.Forms, ...</resheader>
+    <data name="Name1"><value>this is my long string</value><comment>this is a comment</comment></data>
+    <data name="Color1" type="System.Drawing.Color, System.Drawing">Blue</data>
+    <data name="Bitmap1" mimetype="application/x-microsoft.net.object.binary.base64">
+        <value>[base64 mime encoded serialized .NET Framework object]</value>
+    </data>
+    <data name="Icon1" type="System.Drawing.Icon, System.Drawing" mimetype="application/x-microsoft.net.object.bytearray.base64">
+        <value>[base64 mime encoded string representing a byte array form of the .NET Framework object]</value>
+        <comment>This is a comment</comment>
+    </data>
+                
+    There are any number of "resheader" rows that contain simple 
+    name/value pairs.
+    
+    Each data row contains a name, and value. The row also contains a 
+    type or mimetype. Type corresponds to a .NET class that support 
+    text/value conversion through the TypeConverter architecture. 
+    Classes that don't support this are serialized and stored with the 
+    mimetype set.
+    
+    The mimetype is used for serialized objects, and tells the 
+    ResXResourceReader how to depersist the object. This is currently not 
+    extensible. For a given mimetype the value must be set accordingly:
+    
+    Note - application/x-microsoft.net.object.binary.base64 is the format 
+    that the ResXResourceWriter will generate, however the reader can 
+    read any of the formats listed below.
+    
+    mimetype: application/x-microsoft.net.object.binary.base64
+    value   : The object must be serialized with 
+            : System.Runtime.Serialization.Formatters.Binary.BinaryFormatter
+            : and then encoded with base64 encoding.
+    
+    mimetype: application/x-microsoft.net.object.soap.base64
+    value   : The object must be serialized with 
+            : System.Runtime.Serialization.Formatters.Soap.SoapFormatter
+            : and then encoded with base64 encoding.
+
+    mimetype: application/x-microsoft.net.object.bytearray.base64
+    value   : The object must be serialized into a byte array 
+            : using a System.ComponentModel.TypeConverter
+            : and then encoded with base64 encoding.
+    -->
+  <xsd:schema id="root" xmlns="" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:msdata="urn:schemas-microsoft-com:xml-msdata">
+    <xsd:import namespace="http://www.w3.org/XML/1998/namespace" />
+    <xsd:element name="root" msdata:IsDataSet="true">
+      <xsd:complexType>
+        <xsd:choice maxOccurs="unbounded">
+          <xsd:element name="metadata">
+            <xsd:complexType>
+              <xsd:sequence>
+                <xsd:element name="value" type="xsd:string" minOccurs="0" />
+              </xsd:sequence>
+              <xsd:attribute name="name" use="required" type="xsd:string" />
+              <xsd:attribute name="type" type="xsd:string" />
+              <xsd:attribute name="mimetype" type="xsd:string" />
+              <xsd:attribute ref="xml:space" />
+            </xsd:complexType>
+          </xsd:element>
+          <xsd:element name="assembly">
+            <xsd:complexType>
+              <xsd:attribute name="alias" type="xsd:string" />
+              <xsd:attribute name="name" type="xsd:string" />
+            </xsd:complexType>
+          </xsd:element>
+          <xsd:element name="data">
+            <xsd:complexType>
+              <xsd:sequence>
+                <xsd:element name="value" type="xsd:string" minOccurs="0" msdata:Ordinal="1" />
+                <xsd:element name="comment" type="xsd:string" minOccurs="0" msdata:Ordinal="2" />
+              </xsd:sequence>
+              <xsd:attribute name="name" type="xsd:string" use="required" msdata:Ordinal="1" />
+              <xsd:attribute name="type" type="xsd:string" msdata:Ordinal="3" />
+              <xsd:attribute name="mimetype" type="xsd:string" msdata:Ordinal="4" />
+              <xsd:attribute ref="xml:space" />
+            </xsd:complexType>
+          </xsd:element>
+          <xsd:element name="resheader">
+            <xsd:complexType>
+              <xsd:sequence>
+                <xsd:element name="value" type="xsd:string" minOccurs="0" msdata:Ordinal="1" />
+              </xsd:sequence>
+              <xsd:attribute name="name" type="xsd:string" use="required" />
+            </xsd:complexType>
+          </xsd:element>
+        </xsd:choice>
+      </xsd:complexType>
+    </xsd:element>
+  </xsd:schema>
+  <resheader name="resmimetype">
+    <value>text/microsoft-resx</value>
+  </resheader>
+  <resheader name="version">
+    <value>2.0</value>
+  </resheader>
+  <resheader name="reader">
+    <value>System.Resources.ResXResourceReader, System.Windows.Forms, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089</value>
+  </resheader>
+  <resheader name="writer">
+    <value>System.Resources.ResXResourceWriter, System.Windows.Forms, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089</value>
+  </resheader>
+  <data name="AmbiguousEndpoints" xml:space="preserve">
+    <value>Multiple endpoints matched. The following endpoints matched the request:{0}{0}{1}</value>
+    <comment>0 is the newline - 1 is a newline separate list of action display names</comment>
+  </data>
+</root>

src/Microsoft.AspNetCore.Routing/Dispatcher/TreeDispatcher.cs

@@ -14,7 +14,6 @@ using Microsoft.AspNetCore.Routing.Internal;
 using Microsoft.AspNetCore.Routing.Logging;
 using Microsoft.AspNetCore.Routing.Template;
 using Microsoft.AspNetCore.Routing.Tree;
-using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Internal;
 using Microsoft.Extensions.Logging;
 
@@ -23,14 +22,11 @@ namespace Microsoft.AspNetCore.Routing.Dispatcher
     public class TreeDispatcher : DispatcherBase
     {
         private bool _dataInitialized;
-        private bool _servicesInitialized;
         private object _lock;
         private Cache _cache;
 
         private readonly Func<Cache> _initializer;
 
-        private ILogger _logger;
-
         public TreeDispatcher()
         {
             _lock = new object();
@@ -66,14 +62,14 @@ namespace Microsoft.AspNetCore.Routing.Dispatcher
                     {
                         var entry = item.Entry;
                         var matcher = item.TemplateMatcher;
-                        
+
                         values.Clear();
                         if (!matcher.TryMatch(httpContext.Request.Path, values))
                         {
                             continue;
                         }
 
-                        _logger.MatchedRoute(entry.RouteName, entry.RouteTemplate.TemplateText);
+                        Logger.MatchedRoute(entry.RouteName, entry.RouteTemplate.TemplateText);
 
                         if (!MatchConstraints(httpContext, values, entry.Constraints))
                         {
@@ -102,7 +98,7 @@ namespace Microsoft.AspNetCore.Routing.Dispatcher
                         object value;
                         values.TryGetValue(kvp.Key, out value);
 
-                        _logger.RouteValueDoesNotMatchConstraint(value, kvp.Key, kvp.Value);
+                        Logger.RouteValueDoesNotMatchConstraint(value, kvp.Key, kvp.Value);
                         return false;
                     }
                 }
@@ -111,27 +107,6 @@ namespace Microsoft.AspNetCore.Routing.Dispatcher
             return true;
         }
 
-        private void EnsureServicesInitialized(HttpContext httpContext)
-        {
-            if (Volatile.Read(ref _servicesInitialized))
-            {
-                return;
-            }
-
-            EnsureServicesInitializedSlow(httpContext);
-        }
-
-        private void EnsureServicesInitializedSlow(HttpContext httpContext)
-        {
-            lock (_lock)
-            {
-                if (!Volatile.Read(ref _servicesInitialized))
-                {
-                    _logger = httpContext.RequestServices.GetRequiredService<ILogger<TreeDispatcher>>();
-                }
-            }
-        }
-
         private Cache CreateCache()
         {
             var endpoints = GetEndpoints();