Clean up logging.

- Removing scopes as we want to limit the number of scopes being created.
- Added new log statements using the new log format string.

src/Microsoft.AspNet.Mvc.Core/ActionDescriptor.cs

@@ -13,8 +13,14 @@ namespace Microsoft.AspNet.Mvc
         {
             Properties = new Dictionary<object, object>();
             RouteValueDefaults = new Dictionary<string, object>(StringComparer.OrdinalIgnoreCase);
+            Id = Guid.NewGuid().ToString();
         }
 
+        /// <summary>
+        /// Gets an id which uniquely identifies the action.
+        /// </summary>
+        public string Id { get; }
+
         public virtual string Name { get; set; }
 
         public IList<RouteDataActionConstraint> RouteConstraints { get; set; }

src/Microsoft.AspNet.Mvc.Core/DefaultActionSelector.cs

@@ -7,7 +7,6 @@ using System.Linq;
 using System.Threading.Tasks;
 using Microsoft.AspNet.Http;
 using Microsoft.AspNet.Mvc.ActionConstraints;
-using Microsoft.AspNet.Mvc.Logging;
 using Microsoft.AspNet.Mvc.Routing;
 using Microsoft.AspNet.Routing;
 using Microsoft.Framework.Internal;
@@ -36,86 +35,55 @@ namespace Microsoft.AspNet.Mvc.Core
 
         public Task<ActionDescriptor> SelectAsync([NotNull] RouteContext context)
         {
-            using (_logger.BeginScope("DefaultActionSelector.SelectAsync"))
+            var tree = _decisionTreeProvider.DecisionTree;
+            var matchingRouteConstraints = tree.Select(context.RouteData.Values);
+
+            var candidates = new List<ActionSelectorCandidate>();
+            foreach (var action in matchingRouteConstraints)
             {
-                var tree = _decisionTreeProvider.DecisionTree;
+                var constraints = GetConstraints(context.HttpContext, action);
-                var matchingRouteConstraints = tree.Select(context.RouteData.Values);
+                candidates.Add(new ActionSelectorCandidate(action, constraints));
+            }
 
-                var candidates = new List<ActionSelectorCandidate>();
+            var matchingActionConstraints =
-                foreach (var action in matchingRouteConstraints)
+                EvaluateActionConstraints(context, candidates, startingOrder: null);
+
+            List<ActionDescriptor> matchingActions = null;
+            if (matchingActionConstraints != null)
+            {
+                matchingActions = new List<ActionDescriptor>(matchingActionConstraints.Count);
+                foreach (var candidate in matchingActionConstraints)
                 {
-                    var constraints = GetConstraints(context.HttpContext, action);
+                    matchingActions.Add(candidate.Action);
-                    candidates.Add(new ActionSelectorCandidate(action, constraints));
                 }
+            }
 
-                var matchingActionConstraints =
+            var finalMatches = SelectBestActions(matchingActions);
-                    EvaluateActionConstraints(context, candidates, startingOrder: null);
 
-                List<ActionDescriptor> matchingActions = null;
+            if (finalMatches == null || finalMatches.Count == 0)
-                if (matchingActionConstraints != null)
+            {
-                {
+                return Task.FromResult<ActionDescriptor>(null);
-                    matchingActions = new List<ActionDescriptor>(matchingActionConstraints.Count);
+            }
-                    foreach (var candidate in matchingActionConstraints)
+            else if (finalMatches.Count == 1)
-                    {
+            {
-                        matchingActions.Add(candidate.Action);
+                var selectedAction = finalMatches[0];
-                    }
-                }
 
-                var finalMatches = SelectBestActions(matchingActions);
+                return Task.FromResult(selectedAction);
+            }
+            else
+            {
+                var actionNames = string.Join(
+                    Environment.NewLine,
+                    finalMatches.Select(a => a.DisplayName));
 
-                if (finalMatches == null || finalMatches.Count == 0)
+                _logger.LogError("Request matched multiple actions resulting in ambiguity. " +
-                {
+                    "Matching actions: {AmbiguousActions}", actionNames);
-                    if (_logger.IsEnabled(LogLevel.Verbose))
-                    {
-                        _logger.WriteValues(new DefaultActionSelectorSelectAsyncValues()
-                        {
-                            ActionsMatchingRouteConstraints = matchingRouteConstraints,
-                            ActionsMatchingActionConstraints = matchingActions,
-                            FinalMatches = finalMatches,
-                        });
-                    }
 
-                    return Task.FromResult<ActionDescriptor>(null);
+                var message = Resources.FormatDefaultActionSelector_AmbiguousActions(
-                }
+                    Environment.NewLine,
-                else if (finalMatches.Count == 1)
+                    actionNames);
-                {
-                    var selectedAction = finalMatches[0];
 
-                    if (_logger.IsEnabled(LogLevel.Verbose))
+                throw new AmbiguousActionException(message);
-                    {
-                        _logger.WriteValues(new DefaultActionSelectorSelectAsyncValues()
-                        {
-                            ActionsMatchingRouteConstraints = matchingRouteConstraints,
-                            ActionsMatchingActionConstraints = matchingActions,
-                            FinalMatches = finalMatches,
-                            SelectedAction = selectedAction
-                        });
-                    }
-
-                    return Task.FromResult(selectedAction);
-                }
-                else
-                {
-                    if (_logger.IsEnabled(LogLevel.Verbose))
-                    {
-                        _logger.WriteValues(new DefaultActionSelectorSelectAsyncValues()
-                        {
-                            ActionsMatchingRouteConstraints = matchingRouteConstraints,
-                            ActionsMatchingActionConstraints = matchingActions,
-                            FinalMatches = finalMatches,
-                        });
-                    }
-
-                    var actionNames = string.Join(
-                        Environment.NewLine,
-                        finalMatches.Select(a => a.DisplayName));
-
-                    var message = Resources.FormatDefaultActionSelector_AmbiguousActions(
-                        Environment.NewLine,
-                        actionNames);
-
-                    throw new AmbiguousActionException(message);
-                }
             }
         }
 
@@ -184,6 +152,14 @@ namespace Microsoft.AspNet.Mvc.Core
                             if (!constraint.Accept(constraintContext))
                             {
                                 isMatch = false;
+
+                                _logger.LogVerbose(
+                                    "Action '{ActionDisplayName}' with id '{ActionId}' did not match the " +
+                                    "constraint '{ActionConstraint}'", 
+                                    candidate.Action.DisplayName,
+                                    candidate.Action.Id,
+                                    constraint);
+
                                 break;
                             }
                         }

src/Microsoft.AspNet.Mvc.Core/Logging/AttributeRouteRouteAsyncValues.cs

@@ -1,61 +0,0 @@
-// Copyright (c) Microsoft Open Technologies, Inc. All rights reserved.
-// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
-
-using System.Collections.Generic;
-using System.Text;
-using Microsoft.AspNet.Routing.Template;
-
-namespace Microsoft.AspNet.Mvc.Logging
-{
-    /// <summary>
-    /// Represents the state of <see cref="Microsoft.AspNet.Mvc.Routing.AttributeRoute.RouteAsync(
-    /// AspNet.Routing.RouteContext)"/>.
-    /// </summary>
-    public class AttributeRouteRouteAsyncValues
-    {
-        /// <summary>
-        /// The name of the state.
-        /// </summary>
-        public string Name
-        {
-            get
-            {
-                return "AttributeRoute.RouteAsync";
-            }
-        }
-
-        /// <summary>
-        /// The matching routes.
-        /// </summary>
-        public IList<TemplateRoute> MatchingRoutes { get; set; }
-
-        /// <summary>
-        /// True if the request is handled.
-        /// </summary>
-        public bool Handled { get; set; }
-
-        /// <summary>
-        /// A summary of the data for display.
-        /// </summary>
-        public string Summary
-        {
-            get
-            {
-                var builder = new StringBuilder();
-                builder.AppendLine(Name);
-                builder.Append("\tMatching routes: ");
-                StringBuilderHelpers.Append(builder, MatchingRoutes);
-                builder.AppendLine();
-                builder.Append("\tHandled? ");
-                builder.Append(Handled);
-                return builder.ToString();
-            }
-        }
-
-        /// <inheritdoc/>
-        public override string ToString()
-        {
-            return Summary;
-        }
-    }
-}

src/Microsoft.AspNet.Mvc.Core/Logging/DefaultActionSelectorSelectAsyncValues.cs

@@ -1,81 +0,0 @@
-// Copyright (c) Microsoft Open Technologies, Inc. All rights reserved.
-// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
-
-using System.Collections.Generic;
-using System.Text;
-
-namespace Microsoft.AspNet.Mvc.Logging
-{
-    /// <summary>
-    /// Represents the state of <see cref="Core.DefaultActionSelector.SelectAsync(AspNet.Routing.RouteContext)"/>.
-    /// </summary>
-    public class DefaultActionSelectorSelectAsyncValues
-    {
-        /// <summary>
-        /// The name of the state.
-        /// </summary>
-        public string Name
-        {
-            get
-            {
-                return "DefaultActionSelector.SelectAsync";
-            }
-        }
-
-        /// <summary>
-        /// The list of actions that matched all their route constraints, if any.
-        /// </summary>
-        public IReadOnlyList<ActionDescriptor> ActionsMatchingRouteConstraints { get; set; }
-
-        /// <summary>
-        /// The list of actions that matched all their route constraints, and action constraints, if any.
-        /// </summary>
-        public IReadOnlyList<ActionDescriptor> ActionsMatchingActionConstraints { get; set; }
-
-        /// <summary>
-        /// The list of actions that are the best matches. These match all constraints and any additional criteria
-        /// for disambiguation.
-        /// </summary>
-        public IReadOnlyList<ActionDescriptor> FinalMatches { get; set; }
-
-        /// <summary>
-        /// The selected action. Will be null if no matches are found or more than one match is found.
-        /// </summary>
-        public ActionDescriptor SelectedAction { get; set; }
-
-        /// <summary>
-        /// A summary of the data for display.
-        /// </summary>
-        public string Summary
-        {
-            get
-            {
-                var builder = new StringBuilder();
-                builder.AppendLine(Name);
-                builder.Append("\tActions matching route constraints: ");
-                StringBuilderHelpers.Append(builder, ActionsMatchingRouteConstraints, Formatter);
-                builder.AppendLine();
-                builder.Append("\tActions matching action constraints: ");
-                StringBuilderHelpers.Append(builder, ActionsMatchingActionConstraints, Formatter);
-                builder.AppendLine();
-                builder.Append("\tFinal Matches: ");
-                StringBuilderHelpers.Append(builder, FinalMatches, Formatter);
-                builder.AppendLine();
-                builder.Append("\tSelected action: ");
-                builder.Append(Formatter(SelectedAction));
-                return builder.ToString();
-            }
-        }
-
-        /// <inheritdoc/>
-        public override string ToString()
-        {
-            return Summary;
-        }
-
-        private string Formatter(ActionDescriptor descriptor)
-        {
-            return descriptor != null ? descriptor.DisplayName : "No action selected";
-        }
-    }
-}

src/Microsoft.AspNet.Mvc.Core/Logging/MvcRouteHandlerRouteAsyncValues.cs

@@ -1,66 +0,0 @@
-// Copyright (c) Microsoft Open Technologies, Inc. All rights reserved.
-// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
-
-using System.Text;
-
-namespace Microsoft.AspNet.Mvc.Logging
-{
-    /// <summary>
-    /// Represents the state of <see cref="MvcRouteHandler.RouteAsync(AspNet.Routing.RouteContext)"/>.
-    /// </summary>
-    public class MvcRouteHandlerRouteAsyncValues
-    {
-        /// <summary>
-        /// The name of the state.
-        /// </summary>
-        public string Name
-        {
-            get
-            {
-                return "MvcRouteHandler.RouteAsync";
-            }
-        }
-
-        /// <summary>
-        /// True if an action was selected.
-        /// </summary>
-        public bool ActionSelected { get; set; }
-
-        /// <summary>
-        /// True if the selected action was invoked.
-        /// </summary>
-        public bool ActionInvoked { get; set; }
-
-        /// <summary>
-        /// True if the request is handled.
-        /// </summary>
-        public bool Handled { get; set; }
-
-        /// <summary>
-        /// A summary of the data for display.
-        /// </summary>
-        public string Summary
-        {
-            get
-            {
-                var builder = new StringBuilder();
-                builder.AppendLine(Name);
-                builder.Append("\tAction selected? ");
-                builder.Append(ActionSelected);
-                builder.AppendLine();
-                builder.Append("\tAction invoked? ");
-                builder.Append(ActionInvoked);
-                builder.AppendLine();
-                builder.Append("\tHandled? ");
-                builder.Append(Handled);
-                return builder.ToString();
-            }
-        }
-
-        /// <inheritdoc/>
-        public override string ToString()
-        {
-            return Summary;
-        }
-    }
-}

src/Microsoft.AspNet.Mvc.Core/MvcRouteHandler.cs

@@ -2,12 +2,12 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
+using System.Linq;
 using System.Diagnostics;
 using System.Threading.Tasks;
 using Microsoft.AspNet.Http;
 using Microsoft.AspNet.Mvc.Core;
 using Microsoft.AspNet.Mvc.Internal;
-using Microsoft.AspNet.Mvc.Logging;
 using Microsoft.AspNet.Routing;
 using Microsoft.Framework.DependencyInjection;
 using Microsoft.Framework.Internal;
@@ -40,49 +40,49 @@ namespace Microsoft.AspNet.Mvc
             MvcServicesHelper.ThrowIfMvcNotRegistered(services);
 
             EnsureLogger(context.HttpContext);
-            using (_logger.BeginScope("MvcRouteHandler.RouteAsync"))
+            var actionSelector = services.GetRequiredService<IActionSelector>();
+            var actionDescriptor = await actionSelector.SelectAsync(context);
+
+            if (actionDescriptor == null)
             {
-                var actionSelector = services.GetRequiredService<IActionSelector>();
+                _logger.LogVerbose("No actions matched the current request.");
-                var actionDescriptor = await actionSelector.SelectAsync(context);
+                return;
+            }
 
-                if (actionDescriptor == null)
+            // Replacing the route data allows any code running here to dirty the route values or data-tokens
+            // without affecting something upstream.
+            var oldRouteData = context.RouteData;
+            var newRouteData = new RouteData(oldRouteData);
+
+            if (actionDescriptor.RouteValueDefaults != null)
+            {
+                foreach (var kvp in actionDescriptor.RouteValueDefaults)
                 {
-                    LogActionSelection(actionSelected: false, actionInvoked: false, handled: context.IsHandled);
+                    if (!newRouteData.Values.ContainsKey(kvp.Key))
-                    return;
-                }
-
-                // Replacing the route data allows any code running here to dirty the route values or data-tokens
-                // without affecting something upstream.
-                var oldRouteData = context.RouteData;
-                var newRouteData = new RouteData(oldRouteData);
-
-                if (actionDescriptor.RouteValueDefaults != null)
-                {
-                    foreach (var kvp in actionDescriptor.RouteValueDefaults)
                     {
-                        if (!newRouteData.Values.ContainsKey(kvp.Key))
+                        newRouteData.Values.Add(kvp.Key, kvp.Value);
-                        {
-                            newRouteData.Values.Add(kvp.Key, kvp.Value);
-                        }
                     }
                 }
+            }
 
-                try
+            try
+            {
+                context.RouteData = newRouteData;
+
+                using (_logger.BeginScope("ActionId: {ActionId}", actionDescriptor.Id))
                 {
-                    context.RouteData = newRouteData;
+                    _logger.LogVerbose("Executing action {ActionDisplayName}", actionDescriptor.DisplayName);
 
                     await InvokeActionAsync(context, actionDescriptor);
                     context.IsHandled = true;
                 }
-                finally
+            }
+            finally
+            {
+                if (!context.IsHandled)
                 {
-                    if (!context.IsHandled)
+                    context.RouteData = oldRouteData;
-                    {
-                        context.RouteData = oldRouteData;
-                    }
                 }
-
-                LogActionSelection(actionSelected: true, actionInvoked: true, handled: context.IsHandled);
             }
         }
 
@@ -102,8 +102,6 @@ namespace Microsoft.AspNet.Mvc
             var invoker = invokerFactory.CreateInvoker(actionContext);
             if (invoker == null)
             {
-                LogActionSelection(actionSelected: true, actionInvoked: false, handled: context.IsHandled);
-
                 throw new InvalidOperationException(
                     Resources.FormatActionInvokerFactory_CouldNotCreateInvoker(
                         actionDescriptor.DisplayName));
@@ -120,18 +118,5 @@ namespace Microsoft.AspNet.Mvc
                 _logger = factory.CreateLogger<MvcRouteHandler>();
             }
         }
-
-        private void LogActionSelection(bool actionSelected, bool actionInvoked, bool handled)
-        {
-            if (_logger.IsEnabled(LogLevel.Verbose))
-            {
-                _logger.WriteValues(new MvcRouteHandlerRouteAsyncValues()
-                {
-                    ActionSelected = actionSelected,
-                    ActionInvoked = actionInvoked,
-                    Handled = handled,
-                });
-            }
-        }
     }
 }

src/Microsoft.AspNet.Mvc.Core/Routing/InnerAttributeRoute.cs

@@ -7,7 +7,6 @@ using System.Linq;
 using System.Threading.Tasks;
 using Microsoft.AspNet.Mvc.Core;
 using Microsoft.AspNet.Mvc.Internal.Routing;
-using Microsoft.AspNet.Mvc.Logging;
 using Microsoft.AspNet.Routing;
 using Microsoft.AspNet.Routing.Template;
 using Microsoft.Framework.Internal;
@@ -102,42 +101,35 @@ namespace Microsoft.AspNet.Mvc.Routing
         /// <inheritdoc />
         public async Task RouteAsync([NotNull] RouteContext context)
         {
-            using (_logger.BeginScope("AttributeRoute.RouteAsync"))
+            foreach (var route in _matchingRoutes)
             {
-                foreach (var route in _matchingRoutes)
+                var oldRouteData = context.RouteData;
+
+                var newRouteData = new RouteData(oldRouteData);
+                newRouteData.Routers.Add(route);
+
+                try
                 {
-                    var oldRouteData = context.RouteData;
+                    context.RouteData = newRouteData;
-
+                    await route.RouteAsync(context);
-                    var newRouteData = new RouteData(oldRouteData);
+                }
-                    newRouteData.Routers.Add(route);
+                finally
-
+                {
-                    try
+                    if (!context.IsHandled)
                     {
-                        context.RouteData = newRouteData;
+                        context.RouteData = oldRouteData;
-                        await route.RouteAsync(context);
-                    }
-                    finally
-                    {
-                        if (!context.IsHandled)
-                        {
-                            context.RouteData = oldRouteData;
-                        }
                     }
+                }
 
-                    if (context.IsHandled)
+                if (context.IsHandled)
-                    {
+                {
-                        break;
+                    break;
-                    }
                 }
             }
 
-            if (_logger.IsEnabled(LogLevel.Verbose))
+            if (!context.IsHandled)
             {
-                _logger.WriteValues(new AttributeRouteRouteAsyncValues()
+                _logger.LogVerbose("Request did not match any attribute route.");
-                {
-                    MatchingRoutes = _matchingRoutes,
-                    Handled = context.IsHandled
-                });
             }
         }
 

test/Microsoft.AspNet.Mvc.Core.Test/ActionDescriptorValuesTest.cs

@@ -1,23 +0,0 @@
-// Copyright (c) Microsoft Open Technologies, Inc. All rights reserved.
-// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
-
-using Xunit;
-
-namespace Microsoft.AspNet.Mvc.Logging
-{
-    public class ActionDescriptorValuesTest
-    {
-        [Fact]
-        public void ActionDescriptorValues_IncludesAllProperties()
-        {
-            // Arrange
-            var include = new[] { "HttpMethods" };
-
-            // Assert
-            PropertiesAssert.PropertiesAreTheSame(
-                typeof(ControllerActionDescriptor), 
-                typeof(ActionDescriptorValues),
-                include: include);
-        }
-    }
-}

test/Microsoft.AspNet.Mvc.Core.Test/DefaultActionSelectorSelectAsyncValuesTest.cs

@@ -1,30 +0,0 @@
-// Copyright (c) Microsoft Open Technologies, Inc. All rights reserved.
-// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
-
-using System;
-using Xunit;
-
-namespace Microsoft.AspNet.Mvc.Logging
-{
-    public class DefaultActionSelectorSelectAsyncValuesTest
-    {
-        [Fact]
-        public void EmptyDefaultActionSelectorSelectAsyncValues_ReturnValue()
-        {
-            // Arrange
-            var logObject = new DefaultActionSelectorSelectAsyncValues();
-
-            // Act
-            var result = logObject.ToString();
-
-            var expected = "DefaultActionSelector.SelectAsync" + Environment.NewLine +
-                "\tActions matching route constraints: " + Environment.NewLine +
-                "\tActions matching action constraints: " + Environment.NewLine +
-                "\tFinal Matches: " + Environment.NewLine +
-                "\tSelected action: No action selected";
-
-            // Assert
-            Assert.Equal(expected, result);
-        }
-    }
-}

test/Microsoft.AspNet.Mvc.Core.Test/DefaultActionSelectorTests.cs

@@ -25,91 +25,6 @@ namespace Microsoft.AspNet.Mvc
 {
     public class DefaultActionSelectorTests
     {
-        [Fact]
-        public async void SelectAsync_NoMatchedActions_LogIsCorrect()
-        {
-            // Arrange
-            var sink = new TestSink();
-            var loggerFactory = new TestLoggerFactory(sink);
-
-            var routeContext = CreateRouteContext("POST");
-
-            var actions = new ActionDescriptor[0];
-            var selector = CreateSelector(actions, loggerFactory);
-
-            // Act
-            var action = await selector.SelectAsync(routeContext);
-
-            // Assert
-            Assert.Equal(1, sink.Scopes.Count);
-            var scope = sink.Scopes[0];
-            Assert.Equal(typeof(DefaultActionSelector).FullName, scope.LoggerName);
-            Assert.Equal("DefaultActionSelector.SelectAsync", scope.Scope.ToString());
-
-            Assert.Equal(1, sink.Writes.Count);
-
-            var write = sink.Writes[0];
-            Assert.Equal(typeof(DefaultActionSelector).FullName, write.LoggerName);
-            Assert.Equal("DefaultActionSelector.SelectAsync", write.Scope.ToString());
-            var values = Assert.IsType<DefaultActionSelectorSelectAsyncValues>(write.State);
-            Assert.Equal("DefaultActionSelector.SelectAsync", values.Name);
-            Assert.Empty(values.ActionsMatchingRouteConstraints);
-            Assert.Empty(values.ActionsMatchingActionConstraints);
-            Assert.Empty(values.FinalMatches);
-            Assert.Null(values.SelectedAction);
-
-            // (does not throw)
-            Assert.NotEmpty(values.Summary);
-        }
-
-        [Fact]
-        public async void SelectAsync_MatchedActions_LogIsCorrect()
-        {
-            // Arrange
-            var sink = new TestSink();
-            var loggerFactory = new TestLoggerFactory(sink);
-
-            var matched = new ActionDescriptor()
-            {
-                ActionConstraints = new List<IActionConstraintMetadata>()
-                {
-                    new HttpMethodConstraint(new string[] { "POST" }),
-                },
-                Parameters = new List<ParameterDescriptor>(),
-            };
-
-            var notMatched = new ActionDescriptor()
-            {
-                Parameters = new List<ParameterDescriptor>(),
-            };
-
-            var actions = new ActionDescriptor[] { matched, notMatched };
-            var selector = CreateSelector(actions, loggerFactory);
-
-            var routeContext = CreateRouteContext("POST");
-
-            // Act
-            var action = await selector.SelectAsync(routeContext);
-
-            // Assert
-            Assert.Equal(1, sink.Scopes.Count);
-            var scope = sink.Scopes[0];
-            Assert.Equal(typeof(DefaultActionSelector).FullName, scope.LoggerName);
-            Assert.Equal("DefaultActionSelector.SelectAsync", scope.Scope.ToString());
-
-            Assert.Equal(1, sink.Writes.Count);
-
-            var write = sink.Writes[0];
-            Assert.Equal(typeof(DefaultActionSelector).FullName, write.LoggerName);
-            Assert.Equal("DefaultActionSelector.SelectAsync", write.Scope.ToString());
-            var values = Assert.IsType<DefaultActionSelectorSelectAsyncValues>(write.State);
-            Assert.Equal("DefaultActionSelector.SelectAsync", values.Name);
-            Assert.Equal<ActionDescriptor>(actions, values.ActionsMatchingRouteConstraints);
-            Assert.Equal<ActionDescriptor>(new[] { matched }, values.ActionsMatchingActionConstraints);
-            Assert.Equal(matched, Assert.Single(values.FinalMatches));
-            Assert.Equal(matched, values.SelectedAction);
-        }
-
         [Fact]
         public async void SelectAsync_AmbiguousActions_LogIsCorrect()
         {
@@ -122,10 +37,12 @@ namespace Microsoft.AspNet.Mvc
                 new ActionDescriptor() { DisplayName = "A1" },
                 new ActionDescriptor() { DisplayName = "A2" },
             };
-
             var selector = CreateSelector(actions, loggerFactory);
 
             var routeContext = CreateRouteContext("POST");
+            var actionNames = string.Join(Environment.NewLine, actions.Select(action => action.DisplayName));
+            var expectedMessage = "Request matched multiple actions resulting in " +
+                $"ambiguity. Matching actions: {actionNames}";
 
             // Act
             await Assert.ThrowsAsync<AmbiguousActionException>(async () =>
@@ -134,25 +51,9 @@ namespace Microsoft.AspNet.Mvc
             });
 
             // Assert
-            Assert.Equal(1, sink.Scopes.Count);
+            Assert.Empty(sink.Scopes);
-            var scope = sink.Scopes[0];
+            Assert.Single(sink.Writes);
-            Assert.Equal(typeof(DefaultActionSelector).FullName, scope.LoggerName);
+            Assert.Equal(expectedMessage, sink.Writes[0].State?.ToString());
-            Assert.Equal("DefaultActionSelector.SelectAsync", scope.Scope.ToString());
-
-            Assert.Equal(1, sink.Writes.Count);
-
-            var write = sink.Writes[0];
-            Assert.Equal(typeof(DefaultActionSelector).FullName, write.LoggerName);
-            Assert.Equal("DefaultActionSelector.SelectAsync", write.Scope.ToString());
-            var values = Assert.IsType<DefaultActionSelectorSelectAsyncValues>(write.State);
-            Assert.Equal("DefaultActionSelector.SelectAsync", values.Name);
-            Assert.Equal<ActionDescriptor>(actions, values.ActionsMatchingRouteConstraints);
-            Assert.Equal<ActionDescriptor>(actions, values.ActionsMatchingActionConstraints);
-            Assert.Equal<ActionDescriptor>(actions, values.FinalMatches);
-            Assert.Null(values.SelectedAction);
-
-            // (does not throw)
-            Assert.NotEmpty(values.Summary);
         }
 
         [Fact]

test/Microsoft.AspNet.Mvc.Core.Test/MvcRouteHandlerTests.cs

@@ -23,27 +23,22 @@ namespace Microsoft.AspNet.Mvc
             // Arrange
             var sink = new TestSink();
             var loggerFactory = new TestLoggerFactory(sink);
-
+            var displayName = "A.B.C";
-            var context = CreateRouteContext(loggerFactory: loggerFactory);
+            var actionDescriptor = new Mock<ActionDescriptor>();
-
+            actionDescriptor.SetupGet(ad => ad.DisplayName)
+                            .Returns(displayName);
+            var context = CreateRouteContext(actionDescriptor: actionDescriptor.Object, loggerFactory: loggerFactory);
             var handler = new MvcRouteHandler();
+            var expectedMessage = $"Executing action {displayName}";
 
             // Act
             await handler.RouteAsync(context);
 
             // Assert
-            var scope = Assert.Single(sink.Scopes);
+            Assert.Single(sink.Scopes);
-            Assert.Equal(typeof(MvcRouteHandler).FullName, scope.LoggerName);
+            Assert.StartsWith("ActionId: ", sink.Scopes[0].Scope?.ToString());
-            Assert.Equal("MvcRouteHandler.RouteAsync", scope.Scope.ToString());
+            Assert.Single(sink.Writes);
-
+            Assert.Equal(expectedMessage, sink.Writes[0].State?.ToString());
-            var write = Assert.Single(sink.Writes);
-            Assert.Equal(typeof(MvcRouteHandler).FullName, write.LoggerName);
-            Assert.Equal("MvcRouteHandler.RouteAsync", write.Scope.ToString());
-            var values = Assert.IsType<MvcRouteHandlerRouteAsyncValues>(write.State);
-            Assert.Equal("MvcRouteHandler.RouteAsync", values.Name);
-            Assert.True(values.ActionSelected);
-            Assert.True(values.ActionInvoked);
-            Assert.True(values.Handled);
         }
 
         [Fact]
@@ -62,61 +57,15 @@ namespace Microsoft.AspNet.Mvc
                 loggerFactory: loggerFactory);
 
             var handler = new MvcRouteHandler();
+            var expectedMessage = "No actions matched the current request.";
 
             // Act
             await handler.RouteAsync(context);
 
             // Assert
-            var scope = Assert.Single(sink.Scopes);
+            Assert.Empty(sink.Scopes);
-            Assert.Equal(typeof(MvcRouteHandler).FullName, scope.LoggerName);
+            Assert.Single(sink.Writes);
-            Assert.Equal("MvcRouteHandler.RouteAsync", scope.Scope.ToString());
+            Assert.Equal(expectedMessage, sink.Writes[0].State?.ToString());
-
-            var write = Assert.Single(sink.Writes);
-            Assert.Equal(typeof(MvcRouteHandler).FullName, write.LoggerName);
-            Assert.Equal("MvcRouteHandler.RouteAsync", write.Scope.ToString());
-            var values = Assert.IsType<MvcRouteHandlerRouteAsyncValues>(write.State);
-            Assert.Equal("MvcRouteHandler.RouteAsync", values.Name);
-            Assert.False(values.ActionSelected);
-            Assert.False(values.ActionInvoked);
-            Assert.False(values.Handled);
-        }
-
-        [Fact]
-        public async Task RouteAsync_FailOnNoInvoker_LogsCorrectValues()
-        {
-            // Arrange
-            var sink = new TestSink();
-            var loggerFactory = new TestLoggerFactory(sink);
-
-            var mockInvokerFactory = new Mock<IActionInvokerFactory>();
-            mockInvokerFactory.Setup(f => f.CreateInvoker(It.IsAny<ActionContext>()))
-                .Returns<IActionInvoker>(null);
-
-            var context = CreateRouteContext(
-                invokerFactory: mockInvokerFactory.Object,
-                loggerFactory: loggerFactory);
-
-            var handler = new MvcRouteHandler();
-
-            // Act
-            await Assert.ThrowsAsync<InvalidOperationException>(async () =>
-                await handler.RouteAsync(context));
-
-            // Assert
-            var scope = Assert.Single(sink.Scopes);
-            Assert.Equal(typeof(MvcRouteHandler).FullName, scope.LoggerName);
-            Assert.Equal("MvcRouteHandler.RouteAsync", scope.Scope.ToString());
-
-            Assert.Equal(1, sink.Writes.Count);
-
-            var write = sink.Writes[0];
-            Assert.Equal(typeof(MvcRouteHandler).FullName, write.LoggerName);
-            Assert.Equal("MvcRouteHandler.RouteAsync", write.Scope.ToString());
-            var values = Assert.IsType<MvcRouteHandlerRouteAsyncValues>(write.State);
-            Assert.Equal("MvcRouteHandler.RouteAsync", values.Name);
-            Assert.True(values.ActionSelected);
-            Assert.False(values.ActionInvoked);
-            Assert.False(values.Handled);
         }
 
         [Fact]
@@ -241,6 +190,7 @@ namespace Microsoft.AspNet.Mvc
         }
 
         private RouteContext CreateRouteContext(
+            ActionDescriptor actionDescriptor = null,
             IActionSelector actionSelector = null,
             IActionInvokerFactory invokerFactory = null,
             ILoggerFactory loggerFactory = null,
@@ -248,13 +198,17 @@ namespace Microsoft.AspNet.Mvc
         {
             var mockContextAccessor = new Mock<IScopedInstance<ActionContext>>();
 
-            if (actionSelector == null)
+            if (actionDescriptor == null)
             {
                 var mockAction = new Mock<ActionDescriptor>();
+                actionDescriptor = mockAction.Object;
+            }
 
+            if (actionSelector == null)
+            {
                 var mockActionSelector = new Mock<IActionSelector>();
                 mockActionSelector.Setup(a => a.SelectAsync(It.IsAny<RouteContext>()))
-                    .Returns(Task.FromResult(mockAction.Object));
+                    .Returns(Task.FromResult(actionDescriptor));
 
                 actionSelector = mockActionSelector.Object;
             }

test/Microsoft.AspNet.Mvc.Core.Test/Routing/InnerAttributeRouteTest.cs

@@ -907,69 +907,7 @@ namespace Microsoft.AspNet.Mvc.Routing
             Assert.Equal(string.Format("1&{0}", template), selectedGroup);
         }
 
-        [Fact]
+       [Fact]
-        public async void AttributeRoute_RouteAsyncHandled_LogsCorrectValues()
-        {
-            // Arrange
-            var sink = new TestSink();
-            var loggerFactory = new TestLoggerFactory(sink);
-
-            var entry = CreateMatchingEntry("api/Store");
-            var route = CreateRoutingAttributeRoute(loggerFactory, entry);
-
-            var context = CreateRouteContext("/api/Store");
-
-            // Act
-            await route.RouteAsync(context);
-
-            // Assert
-            Assert.Equal(1, sink.Scopes.Count);
-            var scope = sink.Scopes[0];
-            Assert.Equal(typeof(AttributeRoute).FullName, scope.LoggerName);
-            Assert.Equal("AttributeRoute.RouteAsync", scope.Scope.ToString());
-
-            Assert.Equal(1, sink.Writes.Count);
-
-            var write = sink.Writes[0];
-            Assert.Equal(typeof(AttributeRoute).FullName, write.LoggerName);
-            Assert.Equal("AttributeRoute.RouteAsync", write.Scope.ToString());
-            var values = Assert.IsType<AttributeRouteRouteAsyncValues>(write.State);
-            Assert.Equal("AttributeRoute.RouteAsync", values.Name);
-            Assert.True(values.Handled);
-        }
-
-        [Fact]
-        public async void AttributeRoute_RouteAsyncNotHandled_LogsCorrectValues()
-        {
-            // Arrange
-            var sink = new TestSink();
-            var loggerFactory = new TestLoggerFactory(sink);
-
-            var entry = CreateMatchingEntry("api/Store");
-            var route = CreateRoutingAttributeRoute(loggerFactory, entry);
-
-            var context = CreateRouteContext("/");
-
-            // Act
-            await route.RouteAsync(context);
-
-            // Assert
-            Assert.Equal(1, sink.Scopes.Count);
-            var scope = sink.Scopes[0];
-            Assert.Equal(typeof(AttributeRoute).FullName, scope.LoggerName);
-            Assert.Equal("AttributeRoute.RouteAsync", scope.Scope.ToString());
-
-            Assert.Equal(1, sink.Writes.Count);
-
-            var write = sink.Writes[0];
-            Assert.Equal(typeof(AttributeRoute).FullName, write.LoggerName);
-            Assert.Equal("AttributeRoute.RouteAsync", write.Scope.ToString());
-            var values = Assert.IsType<AttributeRouteRouteAsyncValues>(write.State);
-            Assert.Equal("AttributeRoute.RouteAsync", values.Name);
-            Assert.False(values.Handled);
-        }
-
-        [Fact]
         public void AttributeRoute_GenerateLink_NoRequiredValues()
         {
             // Arrange

test/Microsoft.AspNet.Mvc.FunctionalTests/Logging/LoggingActionSelectionTest.cs

@@ -1,102 +0,0 @@
-// Copyright (c) Microsoft Open Technologies, Inc. All rights reserved.
-// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
-
-#if DNX451  // Since Json.net serialization fails in CoreCLR
-using System;
-using System.Collections.Generic;
-using System.Linq;
-using System.Net;
-using System.Net.Http;
-using System.Threading.Tasks;
-using LoggingWebSite;
-using Microsoft.AspNet.Builder;
-using Microsoft.AspNet.Mvc.Logging;
-using Microsoft.Framework.DependencyInjection;
-using Newtonsoft.Json;
-using Xunit;
-
-namespace Microsoft.AspNet.Mvc.FunctionalTests
-{
-    public class LoggingActionSelectionTest
-    {
-        private const string SiteName = nameof(LoggingWebSite);
-        private readonly Action<IApplicationBuilder> _app = new Startup().Configure;
-        private readonly Action<IServiceCollection> _configureServices = new Startup().ConfigureServices;
-
-        [Fact]
-        public async Task Successful_ActionSelection_Logged()
-        {
-            // Arrange
-            var server = TestHelper.CreateServer(_app, SiteName, _configureServices);
-            var client = server.CreateClient();
-            var requestTraceId = Guid.NewGuid().ToString();
-
-            // Act
-            var response = await client.GetAsync(string.Format(
-                                                        "http://localhost/home/index?{0}={1}",
-                                                        LoggingExtensions.RequestTraceIdQueryKey, 
-                                                        requestTraceId));
-
-            // Assert
-            Assert.Equal(HttpStatusCode.OK, response.StatusCode);
-            var responseData = await response.Content.ReadAsStringAsync();
-            Assert.Equal("Home.Index", responseData);
-
-            var logs = await GetLogsAsync(client, requestTraceId);
-            var scopeNode = logs.FindScope(nameof(MvcRouteHandler) + ".RouteAsync");
-
-            Assert.NotNull(scopeNode);
-            var logInfo = scopeNode.Messages.OfDataType<MvcRouteHandlerRouteAsyncValues>()
-                                            .FirstOrDefault();
-                        
-            Assert.NotNull(logInfo);
-            Assert.NotNull(logInfo.State);
-
-            dynamic actionSelection = logInfo.State;
-            Assert.True((bool)actionSelection.ActionSelected);
-            Assert.True((bool)actionSelection.ActionInvoked);
-            Assert.True((bool)actionSelection.Handled);
-        }
-
-        [Fact]
-        public async Task Failed_ActionSelection_Logged()
-        {
-            // Arrange
-            var server = TestHelper.CreateServer(_app, SiteName, _configureServices);
-            var client = server.CreateClient();
-            var requestTraceId = Guid.NewGuid().ToString();
-
-            // Act
-            var response = await client.GetAsync(string.Format(
-                                                        "http://localhost/InvalidController/InvalidAction?{0}={1}",
-                                                        LoggingExtensions.RequestTraceIdQueryKey, 
-                                                        requestTraceId));
-
-            // Assert
-            Assert.Equal(HttpStatusCode.NotFound, response.StatusCode);
-
-
-            var logs = await GetLogsAsync(client, requestTraceId);
-            var scopeNode = logs.FindScope(nameof(MvcRouteHandler) + ".RouteAsync");
-
-            Assert.NotNull(scopeNode);
-            var logInfo = scopeNode.Messages.OfDataType<MvcRouteHandlerRouteAsyncValues>()
-                                            .FirstOrDefault();
-            Assert.NotNull(logInfo);
-
-            dynamic actionSelection = logInfo.State;
-            Assert.False((bool)actionSelection.ActionSelected);
-            Assert.False((bool)actionSelection.ActionInvoked);
-            Assert.False((bool)actionSelection.Handled);
-        }
-
-        private async Task<IEnumerable<ActivityContextDto>> GetLogsAsync(HttpClient client,
-                                                                    string requestTraceId)
-        {
-            var responseData = await client.GetStringAsync("http://localhost/logs");
-            var logActivities = JsonConvert.DeserializeObject<List<ActivityContextDto>>(responseData);
-            return logActivities.FilterByRequestTraceId(requestTraceId);
-        }
-    }
-}
-#endif