Instrumented code to measure execution time of the various layers

JsonApiDotNetCore.sln.DotSettings

@@ -78,7 +78,10 @@ JsonApiDotNetCore.ArgumentGuard.NotNull($EXPR$, $NAME$);</s:String>
 	<s:String x:Key="/Default/CodeInspection/Highlighting/InspectionSeverities/=TailRecursiveCall/@EntryIndexedValue">SUGGESTION</s:String>
 	<s:String x:Key="/Default/CodeInspection/Highlighting/InspectionSeverities/=TryCastAlwaysSucceeds/@EntryIndexedValue">WARNING</s:String>
 	<s:String x:Key="/Default/CodeInspection/Highlighting/InspectionSeverities/=UnnecessaryWhitespace/@EntryIndexedValue">HINT</s:String>
+	<s:String x:Key="/Default/CodeInspection/Highlighting/InspectionSeverities/=UseArrayEmptyMethod/@EntryIndexedValue">WARNING</s:String>
 	<s:String x:Key="/Default/CodeInspection/Highlighting/InspectionSeverities/=UseCollectionCountProperty/@EntryIndexedValue">WARNING</s:String>
+	<s:String x:Key="/Default/CodeInspection/Highlighting/InspectionSeverities/=UseEmptyTypesField/@EntryIndexedValue">WARNING</s:String>
+	<s:String x:Key="/Default/CodeInspection/Highlighting/InspectionSeverities/=UseEventArgsEmptyField/@EntryIndexedValue">WARNING</s:String>
 	<s:String x:Key="/Default/CodeInspection/Highlighting/InspectionSeverities/=VirtualMemberNeverOverridden_002ELocal/@EntryIndexedValue">WARNING</s:String>
 	<s:String x:Key="/Default/CodeStyle/CodeCleanup/Profiles/=JADNC_0020Full_0020Cleanup/@EntryIndexedValue">&lt;?xml version="1.0" encoding="utf-16"?&gt;&lt;Profile name="JADNC Full Cleanup"&gt;&lt;XMLReformatCode&gt;True&lt;/XMLReformatCode&gt;&lt;CSCodeStyleAttributes ArrangeTypeAccessModifier="True" ArrangeTypeMemberAccessModifier="True" SortModifiers="True" RemoveRedundantParentheses="True" AddMissingParentheses="True" ArrangeBraces="True" ArrangeAttributes="True" ArrangeArgumentsStyle="True" ArrangeCodeBodyStyle="True" ArrangeVarStyle="True" ArrangeTrailingCommas="True" ArrangeObjectCreation="True" ArrangeDefaultValue="True" /&gt;&lt;CssAlphabetizeProperties&gt;True&lt;/CssAlphabetizeProperties&gt;&lt;JsInsertSemicolon&gt;True&lt;/JsInsertSemicolon&gt;&lt;FormatAttributeQuoteDescriptor&gt;True&lt;/FormatAttributeQuoteDescriptor&gt;&lt;CorrectVariableKindsDescriptor&gt;True&lt;/CorrectVariableKindsDescriptor&gt;&lt;VariablesToInnerScopesDescriptor&gt;True&lt;/VariablesToInnerScopesDescriptor&gt;&lt;StringToTemplatesDescriptor&gt;True&lt;/StringToTemplatesDescriptor&gt;&lt;JsReformatCode&gt;True&lt;/JsReformatCode&gt;&lt;JsFormatDocComments&gt;True&lt;/JsFormatDocComments&gt;&lt;RemoveRedundantQualifiersTs&gt;True&lt;/RemoveRedundantQualifiersTs&gt;&lt;OptimizeImportsTs&gt;True&lt;/OptimizeImportsTs&gt;&lt;OptimizeReferenceCommentsTs&gt;True&lt;/OptimizeReferenceCommentsTs&gt;&lt;PublicModifierStyleTs&gt;True&lt;/PublicModifierStyleTs&gt;&lt;ExplicitAnyTs&gt;True&lt;/ExplicitAnyTs&gt;&lt;TypeAnnotationStyleTs&gt;True&lt;/TypeAnnotationStyleTs&gt;&lt;RelativePathStyleTs&gt;True&lt;/RelativePathStyleTs&gt;&lt;AsInsteadOfCastTs&gt;True&lt;/AsInsteadOfCastTs&gt;&lt;HtmlReformatCode&gt;True&lt;/HtmlReformatCode&gt;&lt;AspOptimizeRegisterDirectives&gt;True&lt;/AspOptimizeRegisterDirectives&gt;&lt;RemoveCodeRedundancies&gt;True&lt;/RemoveCodeRedundancies&gt;&lt;CSUseAutoProperty&gt;True&lt;/CSUseAutoProperty&gt;&lt;CSMakeFieldReadonly&gt;True&lt;/CSMakeFieldReadonly&gt;&lt;CSMakeAutoPropertyGetOnly&gt;True&lt;/CSMakeAutoPropertyGetOnly&gt;&lt;CSArrangeQualifiers&gt;True&lt;/CSArrangeQualifiers&gt;&lt;CSFixBuiltinTypeReferences&gt;True&lt;/CSFixBuiltinTypeReferences&gt;&lt;CssReformatCode&gt;True&lt;/CssReformatCode&gt;&lt;CSOptimizeUsings&gt;&lt;OptimizeUsings&gt;True&lt;/OptimizeUsings&gt;&lt;EmbraceInRegion&gt;False&lt;/EmbraceInRegion&gt;&lt;RegionName&gt;&lt;/RegionName&gt;&lt;/CSOptimizeUsings&gt;&lt;CSShortenReferences&gt;True&lt;/CSShortenReferences&gt;&lt;CSReformatCode&gt;True&lt;/CSReformatCode&gt;&lt;CSharpFormatDocComments&gt;True&lt;/CSharpFormatDocComments&gt;&lt;CSReorderTypeMembers&gt;True&lt;/CSReorderTypeMembers&gt;&lt;XAMLCollapseEmptyTags&gt;False&lt;/XAMLCollapseEmptyTags&gt;&lt;/Profile&gt;</s:String>
 	<s:String x:Key="/Default/CodeStyle/CodeCleanup/SilentCleanupProfile/@EntryValue">JADNC Full Cleanup</s:String>
@@ -620,15 +623,19 @@ $left$ = $right$;</s:String>
 	<s:String x:Key="/Default/PatternsAndTemplates/StructuralSearch/Pattern/=B3D9EE6B4EC62A4F961EB15F9ADEC2C6/ReplacePattern/@EntryValue">$collection$.IsNullOrEmpty()</s:String>
 	<s:String x:Key="/Default/PatternsAndTemplates/StructuralSearch/Pattern/=B3D9EE6B4EC62A4F961EB15F9ADEC2C6/SearchPattern/@EntryValue">$collection$ == null || !$collection$.Any()</s:String>
 	<s:String x:Key="/Default/PatternsAndTemplates/StructuralSearch/Pattern/=B3D9EE6B4EC62A4F961EB15F9ADEC2C6/Severity/@EntryValue">WARNING</s:String>
+	<s:Boolean x:Key="/Default/UserDictionary/Words/=appsettings/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Assignee/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Injectables/@EntryIndexedValue">True</s:Boolean>
+	<s:Boolean x:Key="/Default/UserDictionary/Words/=jsonapi/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=linebreaks/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Microservices/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=navigations/@EntryIndexedValue">True</s:Boolean>
+	<s:Boolean x:Key="/Default/UserDictionary/Words/=parallelize/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=playlists/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Rewriter/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Startups/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=subdirectory/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=unarchive/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Workflows/@EntryIndexedValue">True</s:Boolean>
+	<s:Boolean x:Key="/Default/UserDictionary/Words/=xunit/@EntryIndexedValue">True</s:Boolean>
 </wpf:ResourceDictionary>

docs/docfx.json

@@ -8,10 +8,7 @@
                 }
             ],
             "dest": "api",
-            "disableGitFeatures": false,
-            "properties": {
-                "targetFramework": "netcoreapp3.1"
-            }
+            "disableGitFeatures": false
         }
     ],
     "build": {

src/Examples/JsonApiDotNetCoreExample/Startups/EmptyStartup.cs

@@ -1,6 +1,7 @@
 using Microsoft.AspNetCore.Builder;
 using Microsoft.AspNetCore.Hosting;
 using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Logging;
 
 namespace JsonApiDotNetCoreExample.Startups
 {
@@ -14,7 +15,9 @@ public virtual void ConfigureServices(IServiceCollection services)
         {
         }
 
-        public virtual void Configure(IApplicationBuilder app, IWebHostEnvironment environment)
+        // ReSharper disable once UnusedMemberInSuper.Global
+        // ReSharper disable once UnusedParameter.Global
+        public virtual void Configure(IApplicationBuilder app, IWebHostEnvironment environment, ILoggerFactory loggerFactory)
         {
         }
     }

src/Examples/JsonApiDotNetCoreExample/Startups/Startup.cs

@@ -1,67 +1,97 @@
 using System;
 using JsonApiDotNetCore.Configuration;
+using JsonApiDotNetCore.Diagnostics;
 using JsonApiDotNetCoreExample.Data;
 using Microsoft.AspNetCore.Authentication;
 using Microsoft.AspNetCore.Builder;
 using Microsoft.AspNetCore.Hosting;
 using Microsoft.EntityFrameworkCore;
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Logging;
 using Newtonsoft.Json;
 using Newtonsoft.Json.Converters;
 
 namespace JsonApiDotNetCoreExample.Startups
 {
     public sealed class Startup : EmptyStartup
     {
+        private readonly ICodeTimerSession _codeTimingSession;
         private readonly string _connectionString;
 
         public Startup(IConfiguration configuration)
         {
+            _codeTimingSession = new DefaultCodeTimerSession();
+            CodeTimingSessionManager.Capture(_codeTimingSession);
+
             string postgresPassword = Environment.GetEnvironmentVariable("PGPASSWORD") ?? "postgres";
             _connectionString = configuration["Data:DefaultConnection"].Replace("###", postgresPassword);
         }
 
         // This method gets called by the runtime. Use this method to add services to the container.
         public override void ConfigureServices(IServiceCollection services)
         {
-            services.AddSingleton<ISystemClock, SystemClock>();
-
-            services.AddDbContext<AppDbContext>(options =>
+            using (CodeTimingSessionManager.Current.Measure("Configure other (startup)"))
             {
-                options.UseNpgsql(_connectionString);
+                services.AddSingleton<ISystemClock, SystemClock>();
+
+                services.AddDbContext<AppDbContext>(options =>
+                {
+                    options.UseNpgsql(_connectionString);
 #if DEBUG
-                options.EnableSensitiveDataLogging();
-                options.EnableDetailedErrors();
+                    options.EnableSensitiveDataLogging();
+                    options.EnableDetailedErrors();
 #endif
-            });
+                });
 
-            services.AddJsonApi<AppDbContext>(options =>
-            {
-                options.Namespace = "api/v1";
-                options.UseRelativeLinks = true;
-                options.ValidateModelState = true;
-                options.IncludeTotalResourceCount = true;
-                options.SerializerSettings.Formatting = Formatting.Indented;
-                options.SerializerSettings.Converters.Add(new StringEnumConverter());
+                using (CodeTimingSessionManager.Current.Measure("Configure JSON:API (startup)"))
+                {
+                    services.AddJsonApi<AppDbContext>(options =>
+                    {
+                        options.Namespace = "api/v1";
+                        options.UseRelativeLinks = true;
+                        options.ValidateModelState = true;
+                        options.IncludeTotalResourceCount = true;
+                        options.SerializerSettings.Formatting = Formatting.Indented;
+                        options.SerializerSettings.Converters.Add(new StringEnumConverter());
 #if DEBUG
-                options.IncludeExceptionStackTraceInErrors = true;
+                        options.IncludeExceptionStackTraceInErrors = true;
 #endif
-            }, discovery => discovery.AddCurrentAssembly());
+                    }, discovery => discovery.AddCurrentAssembly());
+                }
+            }
         }
 
         // This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
-        public override void Configure(IApplicationBuilder app, IWebHostEnvironment environment)
+        public override void Configure(IApplicationBuilder app, IWebHostEnvironment environment, ILoggerFactory loggerFactory)
         {
-            using (IServiceScope scope = app.ApplicationServices.CreateScope())
+            ILogger<Startup> logger = loggerFactory.CreateLogger<Startup>();
+
+            using (CodeTimingSessionManager.Current.Measure("Initialize other (startup)"))
+            {
+                using (IServiceScope scope = app.ApplicationServices.CreateScope())
+                {
+                    var appDbContext = scope.ServiceProvider.GetRequiredService<AppDbContext>();
+                    appDbContext.Database.EnsureCreated();
+                }
+
+                app.UseRouting();
+
+                using (CodeTimingSessionManager.Current.Measure("Initialize JSON:API (startup)"))
+                {
+                    app.UseJsonApi();
+                }
+
+                app.UseEndpoints(endpoints => endpoints.MapControllers());
+            }
+
+            if (CodeTimingSessionManager.IsEnabled)
             {
-                var appDbContext = scope.ServiceProvider.GetRequiredService<AppDbContext>();
-                appDbContext.Database.EnsureCreated();
+                string timingResults = CodeTimingSessionManager.Current.GetResults();
+                logger.LogInformation($"Measurement results for application startup:{Environment.NewLine}{timingResults}");
             }
 
-            app.UseRouting();
-            app.UseJsonApi();
-            app.UseEndpoints(endpoints => endpoints.MapControllers());
+            _codeTimingSession.Dispose();
         }
     }
 }

src/Examples/JsonApiDotNetCoreExample/appsettings.json

@@ -7,7 +7,9 @@
       "Default": "Warning",
       "Microsoft.Hosting.Lifetime": "Warning",
       "Microsoft.EntityFrameworkCore.Update": "Critical",
-      "Microsoft.EntityFrameworkCore.Database.Command": "Critical"
+      "Microsoft.EntityFrameworkCore.Database.Command": "Critical",
+      "JsonApiDotNetCore.Middleware.JsonApiMiddleware": "Information",
+      "JsonApiDotNetCoreExample": "Information"
     }
   },
   "AllowedHosts": "*"

src/JsonApiDotNetCore/Diagnostics/AspNetCodeTimerSession.cs

@@ -0,0 +1,83 @@
+using System;
+using JetBrains.Annotations;
+using Microsoft.AspNetCore.Http;
+
+namespace JsonApiDotNetCore.Diagnostics
+{
+    /// <summary>
+    /// Code timing session management intended for use in ASP.NET Web Applications. Uses <see cref="HttpContext.Items" /> to isolate concurrent requests.
+    /// Can be used with async/wait, but it cannot distinguish between concurrently running threads within a single HTTP request, so you'll need to pass an
+    /// <see cref="CascadingCodeTimer" /> instance through the entire call chain in that case.
+    /// </summary>
+    [PublicAPI]
+    public sealed class AspNetCodeTimerSession : ICodeTimerSession
+    {
+        private const string HttpContextItemKey = "CascadingCodeTimer:Session";
+
+        private readonly HttpContext _httpContext;
+        private readonly IHttpContextAccessor _httpContextAccessor;
+
+        public ICodeTimer CodeTimer
+        {
+            get
+            {
+                HttpContext httpContext = GetHttpContext();
+                var codeTimer = (ICodeTimer)httpContext.Items[HttpContextItemKey];
+
+                if (codeTimer == null)
+                {
+                    codeTimer = new CascadingCodeTimer();
+                    httpContext.Items[HttpContextItemKey] = codeTimer;
+                }
+
+                return codeTimer;
+            }
+        }
+
+        public event EventHandler Disposed;
+
+        public AspNetCodeTimerSession(IHttpContextAccessor httpContextAccessor)
+        {
+            ArgumentGuard.NotNull(httpContextAccessor, nameof(httpContextAccessor));
+
+            _httpContextAccessor = httpContextAccessor;
+        }
+
+        public AspNetCodeTimerSession(HttpContext httpContext)
+        {
+            ArgumentGuard.NotNull(httpContext, nameof(httpContext));
+
+            _httpContext = httpContext;
+        }
+
+        public void Dispose()
+        {
+            HttpContext httpContext = TryGetHttpContext();
+            var codeTimer = (ICodeTimer)httpContext?.Items[HttpContextItemKey];
+
+            if (codeTimer != null)
+            {
+                codeTimer.Dispose();
+                httpContext.Items[HttpContextItemKey] = null;
+            }
+
+            OnDisposed();
+        }
+
+        private void OnDisposed()
+        {
+            Disposed?.Invoke(this, EventArgs.Empty);
+        }
+
+        private HttpContext GetHttpContext()
+        {
+            HttpContext httpContext = TryGetHttpContext();
+            return httpContext ?? throw new InvalidOperationException("An active HTTP request is required.");
+        }
+
+        private HttpContext TryGetHttpContext()
+        {
+            return _httpContext ?? _httpContextAccessor?.HttpContext;
+        }
+    }
+}