Enhance request logging with user context, update packages

Author: pwelter34

Directory.Packages.props

@@ -5,8 +5,7 @@
     <NoWarn>$(NoWarn);NU1507</NoWarn>
   </PropertyGroup>
   <ItemGroup>
-    <PackageVersion Include="Aspire.Hosting.AppHost" Version="13.2.4" />
-    <PackageVersion Include="AspNetCore.SecurityKey" Version="4.2.0" />
+    <PackageVersion Include="AspNetCore.SecurityKey" Version="4.3.0" />
     <PackageVersion Include="AssemblyMetadata.Generators" Version="2.2.0" />
     <PackageVersion Include="AutoMapper" Version="[14.0.0]" />
     <PackageVersion Include="AwesomeAssertions" Version="9.4.0" />
@@ -25,7 +24,7 @@
     <PackageVersion Include="MailKit" Version="4.16.0" />
     <PackageVersion Include="MediatR" Version="[12.5.0]" />
     <PackageVersion Include="MessagePack" Version="3.1.4" />
-    <PackageVersion Include="Meziantou.Analyzer" Version="3.0.72" />
+    <PackageVersion Include="Meziantou.Analyzer" Version="3.0.74" />
     <PackageVersion Include="Microsoft.AspNetCore.Components.WebAssembly" Version="10.0.7" />
     <PackageVersion Include="Microsoft.AspNetCore.Components.WebAssembly.Authentication" Version="10.0.7" />
     <PackageVersion Include="Microsoft.AspNetCore.Components.WebAssembly.Server" Version="10.0.7" />
@@ -72,7 +71,7 @@
     <PackageVersion Include="Testcontainers.MongoDb" Version="4.11.0" />
     <PackageVersion Include="Testcontainers.MsSql" Version="4.11.0" />
     <PackageVersion Include="TUnit" Version="1.43.11" />
-    <PackageVersion Include="Twilio" Version="7.14.8" />
+    <PackageVersion Include="Twilio" Version="7.14.9" />
     <PackageVersion Include="Verify.TUnit" Version="31.16.2" />
     <PackageVersion Include="YamlDotNet" Version="17.1.0" />
   </ItemGroup>

aspire.config.json

@@ -0,0 +1,5 @@
+{
+  "appHost": {
+    "path": "samples/EntityFramework/src/Tracker.Host/Tracker.Host.csproj"
+  }
+}

samples/EntityFramework/src/Tracker.Host/Tracker.Host.csproj

@@ -1,6 +1,4 @@
-<Project Sdk="Microsoft.NET.Sdk">
-
-  <Sdk Name="Aspire.AppHost.Sdk" Version="13.0.0" />
+<Project Sdk="Aspire.AppHost.Sdk/13.3.0">
 
   <PropertyGroup>
     <OutputType>Exe</OutputType>
@@ -11,10 +9,6 @@
     <UserSecretsId>ae704e9f-d42d-4e28-97ab-3459e3af48a9</UserSecretsId>
   </PropertyGroup>
 
-  <ItemGroup>
-    <PackageReference Include="Aspire.Hosting.AppHost" />
-  </ItemGroup>
-
   <ItemGroup>
     <ProjectReference Include="..\Tracker.Service\Tracker.Service.csproj" />
     <ProjectReference Include="..\Tracker.Web\Tracker.Web.csproj" />

src/Arbiter.CommandQuery.Endpoints/RequestLoggingMiddleware.cs

@@ -1,4 +1,5 @@
 using System.Diagnostics;
+using System.Security.Claims;
 using System.Text;
 
 using Arbiter.Services;
@@ -59,15 +60,19 @@ public async Task InvokeAsync(HttpContext context)
             return;
         }
 
-        // track user identity in logs and tracing
-        var userName = context.User?.Identity?.Name ?? "anonymous";
+        var (UserName, UserId) = ResolveUserContext(context);
 
-        // enrich logs with user information
-        using var scope = _logger.BeginScope("{UserName}", userName);
+        // enrich logs with user information for downstream logs
+        // use an array (IReadOnlyList<KeyValuePair<,>>) instead of Dictionary to avoid hashing/bucket allocation
+        using var scope = _logger.BeginScope(new[]
+        {
+            new KeyValuePair<string, object?>("UserName", UserName),
+            new KeyValuePair<string, object?>("UserId", UserId),
+        });
 
         // enrich tracing with user information
-        Activity.Current?.SetTag("enduser.name", userName);
-
+        Activity.Current?.SetTag("enduser.name", UserName);
+        Activity.Current?.SetTag("enduser.id", UserId);
 
         // start timing
         var timestamp = Stopwatch.GetTimestamp();
@@ -203,6 +208,41 @@ private bool ShouldLogBody(HttpRequest request)
         }
     }
 
+
+    private static (string UserName, string UserId) ResolveUserContext(HttpContext context)
+    {
+        var user = context.User;
+        if (user?.Identity?.IsAuthenticated != true)
+            return ("anonymous", "anonymous");
+
+        var userName = ResolveUserName(user);
+        var userId = ResolveUserId(user);
+
+        return (userName, userId);
+    }
+
+    private static string ResolveUserName(ClaimsPrincipal user)
+    {
+        var userName = user.Identity?.Name;
+        if (!string.IsNullOrWhiteSpace(userName))
+            return userName;
+
+        return user.FindFirstValue(ClaimTypes.Name)
+            ?? user.FindFirstValue(ClaimTypes.Upn)
+            ?? user.FindFirstValue(ClaimTypes.Email)
+            ?? user.FindFirstValue(ClaimTypes.NameIdentifier)
+            ?? "anonymous";
+    }
+
+    private static string ResolveUserId(ClaimsPrincipal user)
+    {
+        return user.FindFirstValue(ClaimTypes.NameIdentifier)
+            ?? user.FindFirstValue("sub")
+            ?? user.FindFirstValue("oid")
+            ?? ResolveUserName(user);
+    }
+
+
     [LoggerMessage(EventId = 1, Message = "HTTP {RequestMethod} {RequestPath} responded {StatusCode} in {Elapsed:0.0000} ms")]
     private static partial void LogRequestBasic(ILogger logger, LogLevel logLevel, string? requestMethod, string? requestPath, int statusCode, double elapsed);
 

src/Arbiter.CommandQuery.Endpoints/RequestLoggingMiddlewareExtensions.cs

@@ -17,9 +17,12 @@ public static class RequestLoggingMiddlewareExtensions
     /// <remarks>
     /// This middleware logs HTTP request details including method, path, status code, and elapsed time.
     /// Optionally, it can also log request bodies based on the configured options.
+    /// Register this middleware after <c>UseAuthentication</c> so authenticated user context is available in the logging scope.
     /// </remarks>
     /// <example>
     /// <code>
+    /// app.UseAuthentication();
+    ///
     /// app.UseRequestLogging(options =>
     /// {
     ///     options.LogLevel = LogLevel.Debug;

src/Arbiter.CommandQuery.Endpoints/RequestLoggingOptions.cs

@@ -14,9 +14,15 @@ public class RequestLoggingOptions
     /// <c>true</c> to include the request body; otherwise, <c>false</c>. Default is <c>false</c>.
     /// </value>
     /// <remarks>
+    /// <para>
     /// Enabling request body logging may have a performance impact, especially for large payloads
     /// or high-traffic applications. Use <see cref="RequestBodyMaxSize"/> to limit the size of
     /// logged request bodies and <see cref="RequestBodyMimeTypes"/> to filter which content types are logged.
+    /// </para>
+    /// <para>
+    /// Request bodies can contain sensitive data (for example credentials, tokens, or personal data),
+    /// so enable this setting only when appropriate for your security and compliance requirements.
+    /// </para>
     /// </remarks>
     public bool IncludeRequestBody { get; set; }
 

test/Arbiter.CommandQuery.Endpoints.Tests/RequestLoggingMiddlewareTests.cs

@@ -1,3 +1,4 @@
+using System.Security.Claims;
 using System.Text;
 using Microsoft.AspNetCore.Http;
 using Microsoft.Extensions.Logging;
@@ -79,6 +80,35 @@ public async Task InvokeAsync_DifferentHttpMethods_LogsCorrectMethod(string meth
         logger.LoggedMessages.Should().ContainMatch($"*{method}*{path}*");
     }
 
+    [Test]
+    public async Task InvokeAsync_WhenUserIsAuthenticated_UsesAuthenticatedUserContext()
+    {
+        // Arrange
+        var logger = new FakeLogger<RequestLoggingMiddleware>();
+        var options = CreateOptions();
+        var middleware = new RequestLoggingMiddleware(
+            next: _ => Task.CompletedTask,
+            logger: logger,
+            options: options
+        );
+
+        var context = CreateHttpContext("GET", "/api/test");
+        var identity = new ClaimsIdentity(
+        [
+            new Claim(ClaimTypes.Name, "alice"),
+            new Claim(ClaimTypes.NameIdentifier, "user-123")
+        ],
+        authenticationType: "Test");
+        context.User = new ClaimsPrincipal(identity);
+
+        // Act
+        await middleware.InvokeAsync(context);
+
+        // Assert
+        logger.LastUserName.Should().Be("alice");
+        logger.LastUserId.Should().Be("user-123");
+    }
+
     #endregion
 
     #region Response Status Code Tests
@@ -603,8 +633,22 @@ private class FakeLogger<T> : ILogger<T>
     {
         public List<string> LoggedMessages { get; } = new();
         public LogLevel LogLevel { get; private set; }
+        public string? LastUserName { get; private set; }
+        public string? LastUserId { get; private set; }
 
-        public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
+        public IDisposable? BeginScope<TState>(TState state) where TState : notnull
+        {
+            if (state is IEnumerable<KeyValuePair<string, object?>> values)
+            {
+                var scopeValues = values.ToDictionary(x => x.Key, x => x.Value?.ToString(), StringComparer.Ordinal);
+                scopeValues.TryGetValue("UserName", out var userName);
+                scopeValues.TryGetValue("UserId", out var userId);
+                LastUserName = userName;
+                LastUserId = userId;
+            }
+
+            return NullScope.Instance;
+        }
 
         public bool IsEnabled(LogLevel logLevel) => true;
 
@@ -621,6 +665,15 @@ public void Log<TState>(
         }
     }
 
+    private sealed class NullScope : IDisposable
+    {
+        public static NullScope Instance { get; } = new();
+
+        public void Dispose()
+        {
+        }
+    }
+
     private class ThrowingStream : Stream
     {
         public override bool CanRead => true;