From cea8d019f1c1b2ba044d3da25408244c036f287c Mon Sep 17 00:00:00 2001 From: Ryan Nowak Date: Thu, 22 Oct 2015 18:13:07 -0700 Subject: [PATCH] Add logging and scope for ViewComponent --- samples/MvcSample.Web/Startup.cs | 13 ++- samples/MvcSample.Web/project.json | 69 ++++++++-------- ...ultViewComponentInvokerLoggerExtensions.cs | 79 +++++++++++++++++++ .../DefaultViewComponentInvoker.cs | 67 ++++++++++------ .../DefaultViewComponentInvokerFactory.cs | 10 ++- .../ViewComponents/ViewComponentDescriptor.cs | 43 ++++++++++ 6 files changed, 221 insertions(+), 60 deletions(-) create mode 100644 src/Microsoft.AspNet.Mvc.ViewFeatures/Logging/DefaultViewComponentInvokerLoggerExtensions.cs diff --git a/samples/MvcSample.Web/Startup.cs b/samples/MvcSample.Web/Startup.cs index a3565f5474..c470374ff3 100644 --- a/samples/MvcSample.Web/Startup.cs +++ b/samples/MvcSample.Web/Startup.cs @@ -7,6 +7,7 @@ using Microsoft.AspNet.Localization; using Microsoft.AspNet.Mvc; using Microsoft.AspNet.Mvc.Razor; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; using MvcSample.Web.Filters; using MvcSample.Web.Services; @@ -34,8 +35,18 @@ namespace MvcSample.Web return services.BuildServiceProvider(); } - public void Configure(IApplicationBuilder app) + public void Configure(IApplicationBuilder app, ILoggerFactory loggerFactory) { + loggerFactory.AddConsole((category, level) => + { + if (category.StartsWith("Microsoft.")) + { + return level >= LogLevel.Information; + } + + return level >= LogLevel.Verbose; + }); + app.UseStatusCodePages(); app.UseFileServer(); diff --git a/samples/MvcSample.Web/project.json b/samples/MvcSample.Web/project.json index 8bda7a5b45..aaaf2981f6 100644 --- a/samples/MvcSample.Web/project.json +++ b/samples/MvcSample.Web/project.json @@ -1,36 +1,37 @@ { - "commands": { - "web": "Microsoft.AspNet.Hosting server=Microsoft.AspNet.Server.WebListener server.urls=http://localhost:5001", - "kestrel": "Microsoft.AspNet.Hosting --server Microsoft.AspNet.Server.Kestrel --server.urls http://localhost:5000" - }, - "compilationOptions": { - "warningsAsErrors": true - }, - "dependencies": { - "Microsoft.AspNet.Server.Kestrel": "1.0.0-*", - "Microsoft.AspNet.Diagnostics": "1.0.0-*", - "Microsoft.AspNet.Localization": "1.0.0-*", - "Microsoft.AspNet.Mvc": "6.0.0-*", - "Microsoft.AspNet.Mvc.Formatters.Xml": "6.0.0-*", - "Microsoft.AspNet.Mvc.WebApiCompatShim": "6.0.0-*", - "Microsoft.AspNet.Server.IIS": "1.0.0-*", - "Microsoft.AspNet.Server.WebListener": "1.0.0-*", - "Microsoft.AspNet.Session": "1.0.0-*", - "Microsoft.AspNet.StaticFiles": "1.0.0-*", - "Microsoft.Extensions.Configuration.Json": "1.0.0-*" - }, - "frameworks": { - "dnx451": { }, - "dnxcore50": { } - }, - "exclude": [ - "wwwroot", - "node_modules", - "bower_components" - ], - "publishExclude": [ - "**.user", - "**.vspscc" - ], - "webroot": "wwwroot" + "commands": { + "web": "Microsoft.AspNet.Hosting server=Microsoft.AspNet.Server.WebListener server.urls=http://localhost:5001", + "kestrel": "Microsoft.AspNet.Hosting --server Microsoft.AspNet.Server.Kestrel --server.urls http://localhost:5000" + }, + "compilationOptions": { + "warningsAsErrors": true + }, + "dependencies": { + "Microsoft.AspNet.Server.Kestrel": "1.0.0-*", + "Microsoft.AspNet.Diagnostics": "1.0.0-*", + "Microsoft.AspNet.Localization": "1.0.0-*", + "Microsoft.AspNet.Mvc": "6.0.0-*", + "Microsoft.AspNet.Mvc.Formatters.Xml": "6.0.0-*", + "Microsoft.AspNet.Mvc.WebApiCompatShim": "6.0.0-*", + "Microsoft.AspNet.Server.IIS": "1.0.0-*", + "Microsoft.AspNet.Server.WebListener": "1.0.0-*", + "Microsoft.AspNet.Session": "1.0.0-*", + "Microsoft.AspNet.StaticFiles": "1.0.0-*", + "Microsoft.Extensions.Configuration.Json": "1.0.0-*", + "Microsoft.Extensions.Logging.Console": "1.0.0-*" + }, + "frameworks": { + "dnx451": { }, + "dnxcore50": { } + }, + "exclude": [ + "wwwroot", + "node_modules", + "bower_components" + ], + "publishExclude": [ + "**.user", + "**.vspscc" + ], + "webroot": "wwwroot" } diff --git a/src/Microsoft.AspNet.Mvc.ViewFeatures/Logging/DefaultViewComponentInvokerLoggerExtensions.cs b/src/Microsoft.AspNet.Mvc.ViewFeatures/Logging/DefaultViewComponentInvokerLoggerExtensions.cs new file mode 100644 index 0000000000..f7ada1bf32 --- /dev/null +++ b/src/Microsoft.AspNet.Mvc.ViewFeatures/Logging/DefaultViewComponentInvokerLoggerExtensions.cs @@ -0,0 +1,79 @@ +// 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.Collections.Generic; +using Microsoft.AspNet.Mvc.ViewComponents; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNet.Mvc.ViewFeatures.Logging +{ + public static class DefaultViewComponentInvokerLoggerExtensions + { + private static readonly Action _viewComponentExecuting; + private static readonly Action _viewComponentExecuted; + + static DefaultViewComponentInvokerLoggerExtensions() + { + _viewComponentExecuting = LoggerMessage.Define( + LogLevel.Verbose, + 1, + "Executing view component {ViewComponentName}"); + + _viewComponentExecuted = LoggerMessage.Define( + LogLevel.Verbose, + 2, + "Executed view component {ViewComponentName} in {ElapsedMilliseconds}ms and returned " + + "{ViewComponentResult}"); + } + + public static IDisposable ViewComponentScope(this ILogger logger, ViewComponentContext context) + { + return logger.BeginScopeImpl(new ViewComponentLogScope(context.ViewComponentDescriptor)); + } + + public static void ViewComponentExecuting(this ILogger logger, ViewComponentContext context) + { + _viewComponentExecuting(logger, context.ViewComponentDescriptor.DisplayName, null); + } + + public static void ViewComponentExecuted( + this ILogger logger, + ViewComponentContext context, + int startTime, + object result) + { + var elapsed = new TimeSpan(Environment.TickCount - startTime); + _viewComponentExecuted( + logger, + context.ViewComponentDescriptor.DisplayName, + elapsed.TotalMilliseconds, + Convert.ToString(result), + null); + } + + private class ViewComponentLogScope : ILogValues + { + private readonly ViewComponentDescriptor _descriptor; + + public ViewComponentLogScope(ViewComponentDescriptor descriptor) + { + _descriptor = descriptor; + } + + public IEnumerable> GetValues() + { + return new KeyValuePair[] + { + new KeyValuePair("ViewComponentName", _descriptor.DisplayName), + new KeyValuePair("ViewComponentId", _descriptor.Id), + }; + } + + public override string ToString() + { + return _descriptor.DisplayName; + } + } + } +} diff --git a/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/DefaultViewComponentInvoker.cs b/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/DefaultViewComponentInvoker.cs index a655ab4c86..e2c7aae80e 100644 --- a/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/DefaultViewComponentInvoker.cs +++ b/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/DefaultViewComponentInvoker.cs @@ -11,6 +11,8 @@ using Microsoft.AspNet.Mvc.Diagnostics; using Microsoft.AspNet.Mvc.Infrastructure; using Microsoft.AspNet.Mvc.Rendering; using Microsoft.AspNet.Mvc.ViewFeatures; +using Microsoft.AspNet.Mvc.ViewFeatures.Logging; +using Microsoft.Extensions.Logging; namespace Microsoft.AspNet.Mvc.ViewComponents { @@ -19,11 +21,13 @@ namespace Microsoft.AspNet.Mvc.ViewComponents private readonly ITypeActivatorCache _typeActivatorCache; private readonly IViewComponentActivator _viewComponentActivator; private readonly DiagnosticSource _diagnosticSource; + private readonly ILogger _logger; public DefaultViewComponentInvoker( ITypeActivatorCache typeActivatorCache, IViewComponentActivator viewComponentActivator, - DiagnosticSource diagnosticSource) + DiagnosticSource diagnosticSource, + ILogger logger) { if (typeActivatorCache == null) { @@ -40,9 +44,15 @@ namespace Microsoft.AspNet.Mvc.ViewComponents throw new ArgumentNullException(nameof(diagnosticSource)); } + if (logger == null) + { + throw new ArgumentNullException(nameof(logger)); + } + _typeActivatorCache = typeActivatorCache; _viewComponentActivator = viewComponentActivator; _diagnosticSource = diagnosticSource; + _logger = logger; } public void Invoke(ViewComponentContext context) @@ -135,15 +145,20 @@ namespace Microsoft.AspNet.Mvc.ViewComponents var component = CreateComponent(context); - _diagnosticSource.BeforeViewComponent(context, component); + using (_logger.ViewComponentScope(context)) + { + _diagnosticSource.BeforeViewComponent(context, component); + _logger.ViewComponentExecuting(context); - var result = await ControllerActionExecutor.ExecuteAsync(method, component, context.Arguments); + var startTime = Environment.TickCount; + var result = await ControllerActionExecutor.ExecuteAsync(method, component, context.Arguments); - var viewComponentResult = CoerceToViewComponentResult(result); + var viewComponentResult = CoerceToViewComponentResult(result); + _logger.ViewComponentExecuted(context, startTime, viewComponentResult); + _diagnosticSource.AfterViewComponent(context, viewComponentResult, component); - _diagnosticSource.AfterViewComponent(context, viewComponentResult, component); - - return viewComponentResult; + return viewComponentResult; + } } public IViewComponentResult InvokeSyncCore(MethodInfo method, ViewComponentContext context) @@ -162,24 +177,30 @@ namespace Microsoft.AspNet.Mvc.ViewComponents object result = null; - _diagnosticSource.BeforeViewComponent(context, component); - - try + using (_logger.ViewComponentScope(context)) { - result = method.Invoke(component, context.Arguments); + _diagnosticSource.BeforeViewComponent(context, component); + _logger.ViewComponentExecuting(context); + + try + { + var startTime = Environment.TickCount; + result = method.Invoke(component, context.Arguments); + + var viewComponentResult = CoerceToViewComponentResult(result); + _logger.ViewComponentExecuted(context, startTime, viewComponentResult); + _diagnosticSource.AfterViewComponent(context, viewComponentResult, component); + + return viewComponentResult; + } + catch (TargetInvocationException ex) + { + // Preserve callstack of any user-thrown exceptions. + var exceptionInfo = ExceptionDispatchInfo.Capture(ex.InnerException); + exceptionInfo.Throw(); + return null; // Unreachable + } } - catch (TargetInvocationException ex) - { - // Preserve callstack of any user-thrown exceptions. - var exceptionInfo = ExceptionDispatchInfo.Capture(ex.InnerException); - exceptionInfo.Throw(); - } - - var viewComponentResult = CoerceToViewComponentResult(result); - - _diagnosticSource.AfterViewComponent(context, viewComponentResult, component); - - return viewComponentResult; } private static IViewComponentResult CoerceToViewComponentResult(object value) diff --git a/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/DefaultViewComponentInvokerFactory.cs b/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/DefaultViewComponentInvokerFactory.cs index 0df9ca4d45..3f7ff0920d 100644 --- a/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/DefaultViewComponentInvokerFactory.cs +++ b/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/DefaultViewComponentInvokerFactory.cs @@ -4,6 +4,7 @@ using System; using System.Diagnostics; using Microsoft.AspNet.Mvc.Infrastructure; +using Microsoft.Extensions.Logging; namespace Microsoft.AspNet.Mvc.ViewComponents { @@ -11,16 +12,20 @@ namespace Microsoft.AspNet.Mvc.ViewComponents { private readonly ITypeActivatorCache _typeActivatorCache; private readonly IViewComponentActivator _viewComponentActivator; + private readonly ILogger _logger; private readonly DiagnosticSource _diagnosticSource; public DefaultViewComponentInvokerFactory( ITypeActivatorCache typeActivatorCache, IViewComponentActivator viewComponentActivator, - DiagnosticSource diagnosticSource) + DiagnosticSource diagnosticSource, + ILoggerFactory loggerFactory) { _typeActivatorCache = typeActivatorCache; _viewComponentActivator = viewComponentActivator; _diagnosticSource = diagnosticSource; + + _logger = loggerFactory.CreateLogger(); } /// @@ -37,7 +42,8 @@ namespace Microsoft.AspNet.Mvc.ViewComponents return new DefaultViewComponentInvoker( _typeActivatorCache, _viewComponentActivator, - _diagnosticSource); + _diagnosticSource, + _logger); } } } diff --git a/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/ViewComponentDescriptor.cs b/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/ViewComponentDescriptor.cs index 8bb526313b..22abe0f75d 100644 --- a/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/ViewComponentDescriptor.cs +++ b/src/Microsoft.AspNet.Mvc.ViewFeatures/ViewComponents/ViewComponentDescriptor.cs @@ -2,14 +2,52 @@ // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; +using System.Diagnostics; namespace Microsoft.AspNet.Mvc.ViewComponents { /// /// A descriptor for a View Component. /// + [DebuggerDisplay("{DisplayName}")] public class ViewComponentDescriptor { + private string _displayName; + + /// + /// Creates a new . + /// + public ViewComponentDescriptor() + { + Id = Guid.NewGuid().ToString(); + } + + /// + /// Gets or sets the display name of the View Component. + /// + public string DisplayName + { + get + { + if (_displayName == null) + { + _displayName = Type?.FullName; + } + + return _displayName; + } + + set + { + if (value == null) + { + throw new ArgumentNullException(nameof(value)); + } + + _displayName = value; + } + } + /// /// Gets or sets the full name. /// @@ -41,6 +79,11 @@ namespace Microsoft.AspNet.Mvc.ViewComponents /// public string FullName { get; set; } + /// + /// Gets or set the generated unique identifier for this . + /// + public string Id { get; set; } + /// /// Gets or sets the short name. ///