From 359899538da8bd419daa6d2ab7d38cd0791f7e06 Mon Sep 17 00:00:00 2001 From: Ajay Bhargav Baaskaran Date: Wed, 25 May 2016 15:49:44 -0700 Subject: [PATCH] [Fixes #4291] Simplified MvcRouteHandler code --- .../Internal/ControllerActionInvoker.cs | 90 +++++++----- .../Internal/MvcCoreLoggerExtensions.cs | 4 +- .../Internal/MvcRouteHandler.cs | 51 ++----- .../Infrastructure/MvcRouteHandlerTests.cs | 76 ---------- .../Internal/ControllerActionInvokerTest.cs | 139 +++++++++++++++++- 5 files changed, 207 insertions(+), 153 deletions(-) diff --git a/src/Microsoft.AspNetCore.Mvc.Core/Internal/ControllerActionInvoker.cs b/src/Microsoft.AspNetCore.Mvc.Core/Internal/ControllerActionInvoker.cs index cec356ad37..252b0a0696 100644 --- a/src/Microsoft.AspNetCore.Mvc.Core/Internal/ControllerActionInvoker.cs +++ b/src/Microsoft.AspNetCore.Mvc.Core/Internal/ControllerActionInvoker.cs @@ -112,45 +112,69 @@ public ControllerActionInvoker( public virtual async Task InvokeAsync() { - await InvokeAllAuthorizationFiltersAsync(); - - // If Authorization Filters return a result, it's a short circuit because - // authorization failed. We don't execute Result Filters around the result. - Debug.Assert(_authorizationContext != null); - if (_authorizationContext.Result != null) - { - await InvokeResultAsync(_authorizationContext.Result); - return; - } - try { - await InvokeAllResourceFiltersAsync(); - } - finally - { - // Release the instance after all filters have run. We don't need to surround - // Authorizations filters because the instance will be created much later than - // that. - if (_controller != null) + _diagnosticSource.BeforeAction( + _controllerContext.ActionDescriptor, + _controllerContext.HttpContext, + _controllerContext.RouteData); + + using (_logger.ActionScope(_controllerContext.ActionDescriptor)) { - _controllerFactory.ReleaseController(_controllerContext, _controller); + _logger.ExecutingAction(_controllerContext.ActionDescriptor); + + var startTimestamp = _logger.IsEnabled(LogLevel.Information) ? Stopwatch.GetTimestamp() : 0; + + await InvokeAllAuthorizationFiltersAsync(); + + // If Authorization Filters return a result, it's a short circuit because + // authorization failed. We don't execute Result Filters around the result. + Debug.Assert(_authorizationContext != null); + if (_authorizationContext.Result != null) + { + await InvokeResultAsync(_authorizationContext.Result); + return; + } + + try + { + await InvokeAllResourceFiltersAsync(); + } + finally + { + // Release the instance after all filters have run. We don't need to surround + // Authorizations filters because the instance will be created much later than + // that. + if (_controller != null) + { + _controllerFactory.ReleaseController(_controllerContext, _controller); + } + } + + // We've reached the end of resource filters. If there's an unhandled exception on the context then + // it should be thrown and middleware has a chance to handle it. + Debug.Assert(_resourceExecutedContext != null); + if (_resourceExecutedContext.Exception != null && !_resourceExecutedContext.ExceptionHandled) + { + if (_resourceExecutedContext.ExceptionDispatchInfo == null) + { + throw _resourceExecutedContext.Exception; + } + else + { + _resourceExecutedContext.ExceptionDispatchInfo.Throw(); + } + } + + _logger.ExecutedAction(_controllerContext.ActionDescriptor, startTimestamp); } } - - // We've reached the end of resource filters. If there's an unhandled exception on the context then - // it should be thrown and middleware has a chance to handle it. - Debug.Assert(_resourceExecutedContext != null); - if (_resourceExecutedContext.Exception != null && !_resourceExecutedContext.ExceptionHandled) + finally { - if (_resourceExecutedContext.ExceptionDispatchInfo == null) - { - throw _resourceExecutedContext.Exception; - } - else - { - _resourceExecutedContext.ExceptionDispatchInfo.Throw(); - } + _diagnosticSource.AfterAction( + _controllerContext.ActionDescriptor, + _controllerContext.HttpContext, + _controllerContext.RouteData); } } diff --git a/src/Microsoft.AspNetCore.Mvc.Core/Internal/MvcCoreLoggerExtensions.cs b/src/Microsoft.AspNetCore.Mvc.Core/Internal/MvcCoreLoggerExtensions.cs index 0aeccacfdd..4625992641 100644 --- a/src/Microsoft.AspNetCore.Mvc.Core/Internal/MvcCoreLoggerExtensions.cs +++ b/src/Microsoft.AspNetCore.Mvc.Core/Internal/MvcCoreLoggerExtensions.cs @@ -87,12 +87,12 @@ static MvcCoreLoggerExtensions() _actionMethodExecuting = LoggerMessage.Define( LogLevel.Information, 1, - "Executing action method {ActionName} with arguments ({Arguments}) - ModelState is {ValidationState}'"); + "Executing action method {ActionName} with arguments ({Arguments}) - ModelState is {ValidationState}"); _actionMethodExecuted = LoggerMessage.Define( LogLevel.Debug, 2, - "Executed action method {ActionName}, returned result {ActionResult}.'"); + "Executed action method {ActionName}, returned result {ActionResult}."); _ambiguousActions = LoggerMessage.Define( LogLevel.Error, diff --git a/src/Microsoft.AspNetCore.Mvc.Core/Internal/MvcRouteHandler.cs b/src/Microsoft.AspNetCore.Mvc.Core/Internal/MvcRouteHandler.cs index efcf9e539a..e3f1c05480 100644 --- a/src/Microsoft.AspNetCore.Mvc.Core/Internal/MvcRouteHandler.cs +++ b/src/Microsoft.AspNetCore.Mvc.Core/Internal/MvcRouteHandler.cs @@ -4,8 +4,6 @@ using System; using System.Diagnostics; using System.Threading.Tasks; -using Microsoft.AspNetCore.Http; -using Microsoft.AspNetCore.Mvc.Abstractions; using Microsoft.AspNetCore.Mvc.Core; using Microsoft.AspNetCore.Mvc.Infrastructure; using Microsoft.AspNetCore.Routing; @@ -87,46 +85,23 @@ public Task RouteAsync(RouteContext context) context.RouteData.Values.Remove(TreeRouter.RouteGroupKey); } - context.Handler = (c) => InvokeActionAsync(c, actionDescriptor); - return TaskCache.CompletedTask; - } - - private async Task InvokeActionAsync(HttpContext httpContext, ActionDescriptor actionDescriptor) - { - var routeData = httpContext.GetRouteData(); - try + var routeData = context.HttpContext.GetRouteData(); + var actionContext = new ActionContext(context.HttpContext, routeData, actionDescriptor); + if (_actionContextAccessor != null) { - _diagnosticSource.BeforeAction(actionDescriptor, httpContext, routeData); - - using (_logger.ActionScope(actionDescriptor)) - { - _logger.ExecutingAction(actionDescriptor); - - var startTimestamp = _logger.IsEnabled(LogLevel.Information) ? Stopwatch.GetTimestamp() : 0; - - var actionContext = new ActionContext(httpContext, routeData, actionDescriptor); - if (_actionContextAccessor != null) - { - _actionContextAccessor.ActionContext = actionContext; - } - - var invoker = _actionInvokerFactory.CreateInvoker(actionContext); - if (invoker == null) - { - throw new InvalidOperationException( - Resources.FormatActionInvokerFactory_CouldNotCreateInvoker( - actionDescriptor.DisplayName)); - } - - await invoker.InvokeAsync(); - - _logger.ExecutedAction(actionDescriptor, startTimestamp); - } + _actionContextAccessor.ActionContext = actionContext; } - finally + + var invoker = _actionInvokerFactory.CreateInvoker(actionContext); + if (invoker == null) { - _diagnosticSource.AfterAction(actionDescriptor, httpContext, routeData); + throw new InvalidOperationException( + Resources.FormatActionInvokerFactory_CouldNotCreateInvoker( + actionDescriptor.DisplayName)); } + + context.Handler = async (c) => await invoker.InvokeAsync(); + return TaskCache.CompletedTask; } } } diff --git a/test/Microsoft.AspNetCore.Mvc.Core.Test/Infrastructure/MvcRouteHandlerTests.cs b/test/Microsoft.AspNetCore.Mvc.Core.Test/Infrastructure/MvcRouteHandlerTests.cs index 406c19feb3..c3f18b8ec1 100644 --- a/test/Microsoft.AspNetCore.Mvc.Core.Test/Infrastructure/MvcRouteHandlerTests.cs +++ b/test/Microsoft.AspNetCore.Mvc.Core.Test/Infrastructure/MvcRouteHandlerTests.cs @@ -19,37 +19,6 @@ namespace Microsoft.AspNetCore.Mvc.Infrastructure { public class MvcRouteHandlerTests { - [Fact] - public async Task RouteHandler_Success_LogsCorrectValues() - { - // Arrange - var sink = new TestSink(); - var loggerFactory = new TestLoggerFactory(sink, enabled: true); - - var displayName = "A.B.C"; - var actionDescriptor = new Mock(); - actionDescriptor - .SetupGet(ad => ad.DisplayName) - .Returns(displayName); - - var context = CreateRouteContext(); - - var handler = CreateMvcRouteHandler(actionDescriptor: actionDescriptor.Object, loggerFactory: loggerFactory); - await handler.RouteAsync(context); - - // Act - await context.Handler(context.HttpContext); - - // Assert - Assert.Single(sink.Scopes); - Assert.Equal(displayName, sink.Scopes[0].Scope?.ToString()); - - Assert.Equal(2, sink.Writes.Count); - Assert.Equal($"Executing action {displayName}", sink.Writes[0].State?.ToString()); - // This message has the execution time embedded, which we don't want to verify. - Assert.StartsWith($"Executed action {displayName} ", sink.Writes[1].State?.ToString()); - } - [Fact] public async Task RouteAsync_FailOnNoAction_LogsCorrectValues() { @@ -112,51 +81,6 @@ public async Task RouteHandler_RemovesRouteGroupFromRouteValues() Assert.False(context.RouteData.Values.ContainsKey(TreeRouter.RouteGroupKey)); } - [Fact] - public async Task RouteHandler_WritesDiagnostic_ActionSelected() - { - // Arrange - var listener = new TestDiagnosticListener(); - - var context = CreateRouteContext(); - context.RouteData.Values.Add("tag", "value"); - - var handler = CreateMvcRouteHandler(diagnosticListener: listener); - await handler.RouteAsync(context); - - // Act - await context.Handler(context.HttpContext); - - // Assert - Assert.NotNull(listener.BeforeAction?.ActionDescriptor); - Assert.NotNull(listener.BeforeAction?.HttpContext); - - var routeValues = listener.BeforeAction?.RouteData?.Values; - Assert.NotNull(routeValues); - - Assert.Equal(1, routeValues.Count); - Assert.Contains(routeValues, kvp => kvp.Key == "tag" && string.Equals(kvp.Value, "value")); - } - - [Fact] - public async Task RouteHandler_WritesDiagnostic_ActionInvoked() - { - // Arrange - var listener = new TestDiagnosticListener(); - - var context = CreateRouteContext(); - - var handler = CreateMvcRouteHandler(diagnosticListener: listener); - await handler.RouteAsync(context); - - // Act - await context.Handler(context.HttpContext); - - // Assert - Assert.NotNull(listener.AfterAction?.ActionDescriptor); - Assert.NotNull(listener.AfterAction?.HttpContext); - } - private MvcRouteHandler CreateMvcRouteHandler( ActionDescriptor actionDescriptor = null, IActionSelector actionSelector = null, diff --git a/test/Microsoft.AspNetCore.Mvc.Core.Test/Internal/ControllerActionInvokerTest.cs b/test/Microsoft.AspNetCore.Mvc.Core.Test/Internal/ControllerActionInvokerTest.cs index bbd81d31ca..42e40f7fda 100644 --- a/test/Microsoft.AspNetCore.Mvc.Core.Test/Internal/ControllerActionInvokerTest.cs +++ b/test/Microsoft.AspNetCore.Mvc.Core.Test/Internal/ControllerActionInvokerTest.cs @@ -2480,6 +2480,118 @@ public async Task Invoke_UsesDefaultValuesIfNotBound() Assert.Equal(5, context.Object.Items["Result"]); } + [Fact] + public async Task Invoke_Success_LogsCorrectValues() + { + // Arrange + var sink = new TestSink(); + var loggerFactory = new TestLoggerFactory(sink, enabled: true); + var logger = loggerFactory.CreateLogger(); + + var displayName = "A.B.C"; + var mockActionDescriptor = new Mock(); + mockActionDescriptor + .SetupGet(ad => ad.DisplayName) + .Returns(displayName); + var actionDescriptor = mockActionDescriptor.Object; + actionDescriptor.MethodInfo = typeof(ControllerActionInvokerTest).GetMethod( + nameof(ControllerActionInvokerTest.ActionMethod)); + actionDescriptor.ControllerTypeInfo = typeof(ControllerActionInvokerTest).GetTypeInfo(); + actionDescriptor.FilterDescriptors = new List(); + actionDescriptor.Parameters = new List(); + + var filter = Mock.Of(); + var invoker = CreateInvoker(new[] { filter }, actionDescriptor, null, null, logger: logger); + + // Act + await invoker.InvokeAsync(); + + // Assert + Assert.Single(sink.Scopes); + Assert.Equal(displayName, sink.Scopes[0].Scope?.ToString()); + + Assert.Equal(4, sink.Writes.Count); + Assert.Equal($"Executing action {displayName}", sink.Writes[0].State?.ToString()); + Assert.Equal($"Executing action method {displayName} with arguments () - ModelState is Valid", sink.Writes[1].State?.ToString()); + Assert.Equal($"Executed action method {displayName}, returned result Microsoft.AspNetCore.Mvc.ContentResult.", sink.Writes[2].State?.ToString()); + // This message has the execution time embedded, which we don't want to verify. + Assert.StartsWith($"Executed action {displayName} ", sink.Writes[3].State?.ToString()); + } + + [Fact] + public async Task Invoke_WritesDiagnostic_ActionSelected() + { + // Arrange + var actionDescriptor = new ControllerActionDescriptor() + { + FilterDescriptors = new List(), + Parameters = new List(), + }; + + actionDescriptor.MethodInfo = typeof(ControllerActionInvokerTest).GetMethod( + nameof(ControllerActionInvokerTest.ActionMethod)); + actionDescriptor.ControllerTypeInfo = typeof(ControllerActionInvokerTest).GetTypeInfo(); + + var listener = new TestDiagnosticListener(); + + var routeData = new RouteData(); + routeData.Values.Add("tag", "value"); + + var filter = Mock.Of(); + var invoker = CreateInvoker( + new[] { filter }, + actionDescriptor, + controllerArgumentBinder: null, + controller: null, + diagnosticListener: listener, + routeData: routeData); + + // Act + await invoker.InvokeAsync(); + + // Assert + Assert.NotNull(listener.BeforeAction?.ActionDescriptor); + Assert.NotNull(listener.BeforeAction?.HttpContext); + + var routeValues = listener.BeforeAction?.RouteData?.Values; + Assert.NotNull(routeValues); + + Assert.Equal(1, routeValues.Count); + Assert.Contains(routeValues, kvp => kvp.Key == "tag" && string.Equals(kvp.Value, "value")); + } + + [Fact] + public async Task Invoke_WritesDiagnostic_ActionInvoked() + { + // Arrange + var actionDescriptor = new ControllerActionDescriptor() + { + FilterDescriptors = new List(), + Parameters = new List(), + }; + + actionDescriptor.MethodInfo = typeof(ControllerActionInvokerTest).GetMethod( + nameof(ControllerActionInvokerTest.ActionMethod)); + actionDescriptor.ControllerTypeInfo = typeof(ControllerActionInvokerTest).GetTypeInfo(); + + var listener = new TestDiagnosticListener(); + + var filter = Mock.Of(); + var invoker = CreateInvoker( + new[] { filter }, + actionDescriptor, + controllerArgumentBinder: null, + controller: null, + diagnosticListener: listener); + + // Act + await invoker.InvokeAsync(); + + // Assert + Assert.NotNull(listener.AfterAction?.ActionDescriptor); + Assert.NotNull(listener.AfterAction?.HttpContext); + } + private TestControllerActionInvoker CreateInvoker( IFilterMetadata filter, bool actionThrows = false, @@ -2543,7 +2655,10 @@ private TestControllerActionInvoker CreateInvoker( IControllerArgumentBinder controllerArgumentBinder, object controller, int maxAllowedErrorsInModelState = 200, - List valueProviderFactories = null) + List valueProviderFactories = null, + RouteData routeData = null, + ILogger logger = null, + object diagnosticListener = null) { var httpContext = new Mock(MockBehavior.Loose); @@ -2593,9 +2708,14 @@ private TestControllerActionInvoker CreateInvoker( new TestHttpResponseStreamWriterFactory(), NullLoggerFactory.Instance)); + if (routeData == null) + { + routeData = new RouteData(); + } + var actionContext = new ActionContext( httpContext: httpContext.Object, - routeData: new RouteData(), + routeData: routeData, actionDescriptor: actionDescriptor); var filterProvider = new Mock(MockBehavior.Strict); @@ -2643,12 +2763,23 @@ private TestControllerActionInvoker CreateInvoker( valueProviderFactories = new List(); } + if (logger == null) + { + logger = new NullLoggerFactory().CreateLogger(); + } + + var diagnosticSource = new DiagnosticListener("Microsoft.AspNetCore"); + if (diagnosticListener != null) + { + diagnosticSource.SubscribeWithAdapter(diagnosticListener); + } + var invoker = new TestControllerActionInvoker( new[] { filterProvider.Object }, new MockControllerFactory(controller ?? this), argumentBinder, - new NullLoggerFactory().CreateLogger(), - new DiagnosticListener("Microsoft.AspNetCore"), + logger, + diagnosticSource, actionContext, valueProviderFactories.AsReadOnly(), maxAllowedErrorsInModelState);