Log request performance

src/Squidex/Config/Domain/InfrastructureModule.cs

@@ -22,6 +22,7 @@ using Squidex.Infrastructure.Caching;
 using Squidex.Infrastructure.CQRS.Commands;
 using Squidex.Infrastructure.CQRS.Events;
 using Squidex.Infrastructure.Log;
+using Squidex.Pipeline;
 using IntrospectionExtensions = System.Reflection.IntrospectionExtensions;
 
 // ReSharper disable UnusedAutoPropertyAccessor.Local
@@ -56,7 +57,11 @@ namespace Squidex.Config.Domain
                 .As<ILogAppender>()
                 .SingleInstance();
 
-            builder.Register(c => new TimestampLogAppender())
+            builder.RegisterType<ActionContextLogAppender>()
+                .As<ILogAppender>()
+                .SingleInstance();
+
+            builder.RegisterType<TimestampLogAppender>()
                 .As<ILogAppender>()
                 .SingleInstance();
 

src/Squidex/Config/Web/WebDependencies.cs

@@ -8,6 +8,7 @@
 
 using Microsoft.Extensions.DependencyInjection;
 using Squidex.Config.Domain;
+using Squidex.Pipeline;
 
 namespace Squidex.Config.Web
 {
@@ -15,7 +16,10 @@ namespace Squidex.Config.Web
     {
         public static void AddMyMvc(this IServiceCollection services)
         {
-            services.AddMvc().AddMySerializers();
+            services.AddMvc(options =>
+            {
+                options.Filters.Add(typeof(LogPerformanceAttribute));
+            }).AddMySerializers();
         }
     }
 }

src/Squidex/Config/Web/WebUsages.cs

@@ -21,7 +21,12 @@ namespace Squidex.Config.Web
     {
         public static void UseMyForwardingRules(this IApplicationBuilder app)
         {
-            app.UseForwardedHeaders(new ForwardedHeadersOptions { ForwardedHeaders = ForwardedHeaders.XForwardedProto, RequireHeaderSymmetry = false });
+            app.UseForwardedHeaders(new ForwardedHeadersOptions
+            {
+                ForwardedHeaders = ForwardedHeaders.XForwardedProto,
+                ForwardLimit = null,
+                RequireHeaderSymmetry = false
+            });
 
             app.UseMiddleware<EnforceHttpsMiddleware>();
         }

src/Squidex/Controllers/UI/Account/AccountController.cs

@@ -16,7 +16,6 @@ using IdentityServer4.Services;
 using Microsoft.AspNetCore.Identity;
 using Microsoft.AspNetCore.Identity.MongoDB;
 using Microsoft.AspNetCore.Mvc;
-using Microsoft.Extensions.Logging;
 using NSwag.Annotations;
 using Microsoft.Extensions.Options;
 using Squidex.Config;

src/Squidex/Pipeline/ActionContextLogAppender.cs

@@ -0,0 +1,59 @@
+// ==========================================================================
+//  HttpLogAppender.cs
+//  Squidex Headless CMS
+// ==========================================================================
+//  Copyright (c) Squidex Group
+//  All rights reserved.
+// ==========================================================================
+
+using System;
+using Microsoft.AspNetCore.Mvc.Infrastructure;
+using Squidex.Infrastructure.Log;
+
+namespace Squidex.Pipeline
+{
+    public class ActionContextLogAppender : ILogAppender
+    {
+        private readonly IActionContextAccessor actionContextAccessor;
+
+        public ActionContextLogAppender(IActionContextAccessor actionContextAccessor)
+        {
+            this.actionContextAccessor = actionContextAccessor;
+        }
+
+        public void Append(IObjectWriter writer)
+        {
+            var actionContext = actionContextAccessor.ActionContext;
+
+            if (actionContext == null)
+            {
+                return;
+            }
+
+            var httpContext = actionContext.HttpContext;
+
+            Guid requestId;
+
+            if (httpContext.Items.TryGetValue(nameof(requestId), out var value) && value is Guid requestIdValue)
+            {
+                requestId = requestIdValue;
+            }
+            else
+            {
+                httpContext.Items[nameof(requestId)] = requestId = Guid.NewGuid();
+            }
+
+            writer.WriteObject("web", w => w
+                .WriteProperty("requestId", requestId.ToString())
+                .WriteProperty("requestPath", httpContext.Request.Path)
+                .WriteProperty("requestMethod", httpContext.Request.Method)
+                .WriteObject("routeValues", r =>
+                {
+                    foreach (var kvp in actionContext.ActionDescriptor.RouteValues)
+                    {
+                        r.WriteProperty(kvp.Key, kvp.Value);
+                    }
+                }));
+        }
+    }
+}

src/Squidex/Pipeline/LogPerformanceAttribute.cs

@@ -0,0 +1,36 @@
+// ==========================================================================
+//  LogPerformanceAttribute.cs
+//  Squidex Headless CMS
+// ==========================================================================
+//  Copyright (c) Squidex Group
+//  All rights reserved.
+// ==========================================================================
+
+using System.Diagnostics;
+using Microsoft.AspNetCore.Mvc.Filters;
+using Squidex.Infrastructure.Log;
+
+namespace Squidex.Pipeline
+{
+    public sealed class LogPerformanceAttribute : ActionFilterAttribute
+    {
+        private readonly ISemanticLog log;
+
+        public LogPerformanceAttribute(ISemanticLog log)
+        {
+            this.log = log;
+        }
+
+        public override void OnActionExecuting(ActionExecutingContext context)
+        {
+            context.HttpContext.Items["Watch"] = Stopwatch.StartNew();
+        }
+
+        public override void OnActionExecuted(ActionExecutedContext context)
+        {
+            var stopWatch = (Stopwatch)context.HttpContext.Items["Watch"];
+
+            log.LogInformation(w => w.WriteProperty("elapsedRequestMs", stopWatch.ElapsedMilliseconds));
+        }
+    }
+}