diff --git a/SharedKernel.Demo/MassTransitExtensions.cs b/SharedKernel.Demo/MassTransitExtensions.cs index 3da39c2..228581c 100644 --- a/SharedKernel.Demo/MassTransitExtensions.cs +++ b/SharedKernel.Demo/MassTransitExtensions.cs @@ -12,25 +12,47 @@ public static WebApplicationBuilder AddMassTransit(this WebApplicationBuilder bu { x.AddConsumers(assemblies); x.SetKebabCaseEndpointNameFormatter(); + + // Quorum queue for HA — apply regardless of env so staging mirrors prod. + // Degrades gracefully on single-node (still works, just no replication). + x.AddConfigureEndpointsCallback((_, cfg) => + { + if (cfg is IRabbitMqReceiveEndpointConfigurator rmq && builder.Environment.IsProduction()) + { + rmq.SetQuorumQueue(3); + } + }); + x.UsingRabbitMq((context, cfg) => { cfg.Host(builder.Configuration.GetConnectionString("RabbitMq")!); - cfg.ConfigureEndpoints(context); + + // Required for UseDelayedRedelivery to bind to the RabbitMQ delayed exchange plugin. + cfg.UseDelayedMessageScheduler(); + + // Outer: delayed redelivery — survives 3rd-party outages. + // After exhaustion → *_error queue for manual intervention / alerting. + cfg.UseDelayedRedelivery(r => r.Intervals( + TimeSpan.FromMinutes(5), + TimeSpan.FromMinutes(30), + TimeSpan.FromHours(2), + TimeSpan.FromHours(6), + TimeSpan.FromHours(12), + TimeSpan.FromHours(24))); + + // Inner: immediate in-process retries for transient faults (network blip, deadlock). + // Keep low — expensive failures should flow to delayed redelivery fast. cfg.UseMessageRetry(r => - r.Exponential(5, TimeSpan.FromSeconds(30), TimeSpan.FromHours(1), TimeSpan.FromSeconds(60))); - - //Approximate Retry Timings: - //Retry Attempt Approximate Delay - //1st Retry 30 sec - //2nd Retry ~5 min - //3rd Retry ~15 min - //4th Retry ~30 min - //5th Retry ~1 hour(capped) + r.Exponential(4, TimeSpan.FromMilliseconds(200), TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(2))); + + // Tune based on consumer count and message processing time. Higher → better throughput but more messages in-flight (potentially out of order). + cfg.PrefetchCount = 32; + + cfg.ConfigureEndpoints(context); }); }); builder.AddRmqHealthCheck(); - return builder; } } @@ -47,6 +69,7 @@ public static WebApplicationBuilder AddRmqHealthCheck(this WebApplicationBuilder { Uri = new Uri(rmqConnectionString) }; + return factory.CreateConnectionAsync() .GetAwaiter() .GetResult(); diff --git a/SharedKernel.Demo/appsettings.Development.json b/SharedKernel.Demo/appsettings.Development.json index 02b006c..84322d4 100644 --- a/SharedKernel.Demo/appsettings.Development.json +++ b/SharedKernel.Demo/appsettings.Development.json @@ -3,8 +3,8 @@ "MinimumLevel": { "Default": "Information", "Override": { - "Microsoft": "Information", - "System": "Information" + "Microsoft": "Warning", + "System": "Warning" } } }, diff --git a/src/SharedKernel/Logging/LogCleanupHostedService.cs b/src/SharedKernel/Logging/LogCleanupHostedService.cs index 7167cdf..a499841 100644 --- a/src/SharedKernel/Logging/LogCleanupHostedService.cs +++ b/src/SharedKernel/Logging/LogCleanupHostedService.cs @@ -5,6 +5,7 @@ namespace SharedKernel.Logging; public class LogCleanupHostedService(string logsDirectory, TimeSpan retentionPeriod) : BackgroundService { + /// protected override async Task ExecuteAsync(CancellationToken stoppingToken) { while (!stoppingToken.IsCancellationRequested) diff --git a/src/SharedKernel/Logging/Middleware/CappedResponseBodyStream.cs b/src/SharedKernel/Logging/Middleware/CappedResponseBodyStream.cs index 95654df..6315490 100644 --- a/src/SharedKernel/Logging/Middleware/CappedResponseBodyStream.cs +++ b/src/SharedKernel/Logging/Middleware/CappedResponseBodyStream.cs @@ -25,11 +25,15 @@ public override long Position private void Capture(ReadOnlySpan source) { if (_bufferLength >= capBytes) + { return; + } var toCopy = Math.Min(capBytes - _bufferLength, source.Length); if (toCopy <= 0) + { return; + } source[..toCopy] .CopyTo(_buffer.AsSpan(_bufferLength)); @@ -43,11 +47,10 @@ public override void Write(byte[] buffer, int offset, int count) Capture(buffer.AsSpan(offset, count)); } + // Delegates to the ValueTask overload to unify capture logic and avoid duplication. public override async Task WriteAsync(byte[] buffer, int offset, int count, CancellationToken cancellationToken) { - await inner.WriteAsync(buffer.AsMemory(offset, count), cancellationToken); - TotalWritten += count; - Capture(buffer.AsSpan(offset, count)); + await WriteAsync(buffer.AsMemory(offset, count), cancellationToken); } public override ValueTask WriteAsync(ReadOnlyMemory buffer, CancellationToken cancellationToken = default) @@ -65,21 +68,27 @@ public override ValueTask WriteAsync(ReadOnlyMemory buffer, CancellationTo protected override void Dispose(bool disposing) { if (_disposed) + { return; + } _disposed = true; ArrayPool.Shared.Return(_buffer); base.Dispose(disposing); } - public override ValueTask DisposeAsync() + // Bug fix: original skipped base.DisposeAsync(), leaving the finalizer un-suppressed + // and the inner stream without an async-dispose signal through the chain. + public override async ValueTask DisposeAsync() { if (_disposed) - return ValueTask.CompletedTask; + { + return; + } _disposed = true; ArrayPool.Shared.Return(_buffer); - return ValueTask.CompletedTask; + await base.DisposeAsync(); } public override int Read(byte[] buffer, int offset, int count) => throw new NotSupportedException(); diff --git a/src/SharedKernel/Logging/Middleware/HttpLogHelper.cs b/src/SharedKernel/Logging/Middleware/HttpLogHelper.cs index 5693463..e907421 100644 --- a/src/SharedKernel/Logging/Middleware/HttpLogHelper.cs +++ b/src/SharedKernel/Logging/Middleware/HttpLogHelper.cs @@ -6,155 +6,172 @@ namespace SharedKernel.Logging.Middleware; internal static class HttpLogHelper { - public static async Task<(object Headers, object Body)> CaptureAsync( - Stream bodyStream, - IHeaderDictionary headers, - string? contentType, - CancellationToken ct = default) - { - var redactedHeaders = RedactionHelper.RedactHeaders(headers); - - var textLike = MediaTypeUtil.IsTextLike(contentType); - var hasContentLength = headers.ContainsKey(HeaderNames.ContentLength); - var contentLength = GetContentLengthOrNull(headers); - var hasChunked = headers.ContainsKey(HeaderNames.TransferEncoding); - - // Empty body detection - if ((hasContentLength && contentLength == 0) || - (!hasContentLength && !hasChunked && string.IsNullOrWhiteSpace(contentType))) - { - return (redactedHeaders, new Dictionary()); - } - - if (!textLike) - { - return (redactedHeaders, LogFormatting.Omitted( - "non-text", - contentLength, - MediaTypeUtil.Normalize(contentType), - LoggingOptions.RequestResponseBodyMaxBytes)); - } - - var (raw, truncated) = await ReadLimitedAsync(bodyStream, LoggingOptions.RequestResponseBodyMaxBytes, ct); - - if (truncated) - { - return (redactedHeaders, LogFormatting.Omitted( - "exceeds-limit", - LoggingOptions.RequestResponseBodyMaxBytes, - MediaTypeUtil.Normalize(contentType), - LoggingOptions.RequestResponseBodyMaxBytes)); - } - - var body = RedactionHelper.RedactBody(contentType, raw); - return (redactedHeaders, body); - } - - public static async Task<(object Headers, object Body)> CaptureAsync( - Dictionary> headers, - Func> rawReader, - string? contentType, - CancellationToken ct = default) - { - var redactedHeaders = RedactionHelper.RedactHeaders(headers); - - if (!MediaTypeUtil.IsTextLike(contentType)) - return (redactedHeaders, new Dictionary()); - - var raw = await rawReader(); - var byteCount = Encoding.UTF8.GetByteCount(raw); - - if (byteCount > LoggingOptions.RequestResponseBodyMaxBytes) - { - return (redactedHeaders, LogFormatting.Omitted( - "exceeds-limit", - byteCount, - MediaTypeUtil.Normalize(contentType), - LoggingOptions.RequestResponseBodyMaxBytes)); - } - - var body = RedactionHelper.RedactBody(contentType, raw); - return (redactedHeaders, body); - } - - public static Dictionary> CreateHeadersDictionary(HttpRequestMessage request) - { - var dict = new Dictionary>(StringComparer.OrdinalIgnoreCase); - - foreach (var header in request.Headers) + public static async Task<(object Headers, object Body)> CaptureAsync(Stream bodyStream, + IHeaderDictionary headers, + string? contentType, + CancellationToken ct = default) + { + var redactedHeaders = RedactionHelper.RedactHeaders(headers); + + var textLike = MediaTypeUtil.IsTextLike(contentType); + var hasContentLength = headers.ContainsKey(HeaderNames.ContentLength); + var contentLength = GetContentLengthOrNull(headers); + var hasChunked = headers.ContainsKey(HeaderNames.TransferEncoding); + + // Empty body detection + if ((hasContentLength && contentLength == 0) || + (!hasContentLength && !hasChunked && string.IsNullOrWhiteSpace(contentType))) + { + return (redactedHeaders, new Dictionary()); + } + + if (!textLike) + { + return (redactedHeaders, LogFormatting.Omitted( + "non-text", + contentLength, + MediaTypeUtil.Normalize(contentType), + LoggingOptions.RequestResponseBodyMaxBytes)); + } + + var (raw, truncated) = await ReadLimitedAsync(bodyStream, LoggingOptions.RequestResponseBodyMaxBytes, ct); + + if (truncated) + { + return (redactedHeaders, LogFormatting.Omitted( + "exceeds-limit", + LoggingOptions.RequestResponseBodyMaxBytes, + MediaTypeUtil.Normalize(contentType), + LoggingOptions.RequestResponseBodyMaxBytes)); + } + + var body = RedactionHelper.RedactBody(contentType, raw); + return (redactedHeaders, body); + } + + public static async Task<(object Headers, object Body)> CaptureAsync(Dictionary> headers, + Func> rawReader, + string? contentType, + CancellationToken ct = default) + { + var redactedHeaders = RedactionHelper.RedactHeaders(headers); + + if (!MediaTypeUtil.IsTextLike(contentType)) + { + return (redactedHeaders, new Dictionary()); + } + + var raw = await rawReader(); + var byteCount = Encoding.UTF8.GetByteCount(raw); + + if (byteCount > LoggingOptions.RequestResponseBodyMaxBytes) + { + return (redactedHeaders, LogFormatting.Omitted( + "exceeds-limit", + byteCount, + MediaTypeUtil.Normalize(contentType), + LoggingOptions.RequestResponseBodyMaxBytes)); + } + + var body = RedactionHelper.RedactBody(contentType, raw); + return (redactedHeaders, body); + } + + public static Dictionary> CreateHeadersDictionary(HttpRequestMessage request) + { + var dict = new Dictionary>(StringComparer.OrdinalIgnoreCase); + + foreach (var header in request.Headers) + { + dict[header.Key] = header.Value; + } + + if (request.Content?.Headers is { } contentHeaders) + { + foreach (var header in contentHeaders) + { dict[header.Key] = header.Value; - - if (request.Content?.Headers is { } contentHeaders) - { - foreach (var header in contentHeaders) - dict[header.Key] = header.Value; - } - - return dict; - } - - public static Dictionary> CreateHeadersDictionary(HttpResponseMessage response) - { - var dict = new Dictionary>(StringComparer.OrdinalIgnoreCase); - - foreach (var header in response.Headers) - dict[header.Key] = header.Value; - - foreach (var header in response.Content.Headers) - dict[header.Key] = header.Value; - - return dict; - } - - private static long? GetContentLengthOrNull(IHeaderDictionary headers) - { - if (headers.TryGetValue(HeaderNames.ContentLength, out var value) && - long.TryParse(value.ToString(), out var contentLength)) - { - return contentLength; - } - return null; - } - - private static async Task<(string text, bool truncated)> ReadLimitedAsync( - Stream stream, - int maxBytes, - CancellationToken ct = default) - { - stream.Seek(0, SeekOrigin.Begin); - - using var memoryStream = new MemoryStream(maxBytes); - var buffer = new byte[Math.Min(8192, maxBytes)]; - var totalRead = 0; - - while (totalRead < maxBytes) - { - var toRead = Math.Min(buffer.Length, maxBytes - totalRead); - var bytesRead = await stream.ReadAsync(buffer.AsMemory(0, toRead), ct); - - if (bytesRead == 0) - break; - - await memoryStream.WriteAsync(buffer.AsMemory(0, bytesRead), ct); - totalRead += bytesRead; - } - - var truncated = false; - - if (totalRead == maxBytes) - { - var probe = new byte[1]; - var probeRead = await stream.ReadAsync(probe.AsMemory(0, 1), ct); - - if (probeRead > 0) - { - truncated = true; - if (stream.CanSeek) - stream.Seek(-probeRead, SeekOrigin.Current); - } - } - - stream.Seek(0, SeekOrigin.Begin); - return (Encoding.UTF8.GetString(memoryStream.ToArray()), truncated); - } + } + } + + return dict; + } + + public static Dictionary> CreateHeadersDictionary(HttpResponseMessage response) + { + var dict = new Dictionary>(StringComparer.OrdinalIgnoreCase); + + foreach (var header in response.Headers) + { + dict[header.Key] = header.Value; + } + + foreach (var header in response.Content.Headers) + { + dict[header.Key] = header.Value; + } + + return dict; + } + + private static long? GetContentLengthOrNull(IHeaderDictionary headers) + { + if (headers.TryGetValue(HeaderNames.ContentLength, out var value) && + long.TryParse(value.ToString(), out var contentLength)) + { + return contentLength; + } + + return null; + } + + private static async Task<(string text, bool truncated)> ReadLimitedAsync(Stream stream, + int maxBytes, + CancellationToken ct = default) + { + if (!stream.CanSeek) + { + throw new InvalidOperationException( + "Stream must support seeking. Call EnableBuffering() before passing the request body."); + } + + stream.Seek(0, SeekOrigin.Begin); + + using var memoryStream = new MemoryStream(maxBytes); + var buffer = new byte[Math.Min(8192, maxBytes)]; + var totalRead = 0; + + while (totalRead < maxBytes) + { + var toRead = Math.Min(buffer.Length, maxBytes - totalRead); + var bytesRead = await stream.ReadAsync(buffer.AsMemory(0, toRead), ct); + + if (bytesRead == 0) + { + break; + } + + await memoryStream.WriteAsync(buffer.AsMemory(0, bytesRead), ct); + totalRead += bytesRead; + } + + var truncated = false; + + if (totalRead == maxBytes) + { + var probe = new byte[1]; + var probeRead = await stream.ReadAsync(probe.AsMemory(0, 1), ct); + + if (probeRead > 0) + { + truncated = true; + stream.Seek(-probeRead, SeekOrigin.Current); + } + } + + stream.Seek(0, SeekOrigin.Begin); + + // GetBuffer() avoids the extra heap copy that ToArray() would introduce. + return (Encoding.UTF8.GetString(memoryStream.GetBuffer(), 0, (int)memoryStream.Length), truncated); + } } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/LoggingExtensions.cs b/src/SharedKernel/Logging/Middleware/LoggingExtensions.cs index b72623c..3629480 100644 --- a/src/SharedKernel/Logging/Middleware/LoggingExtensions.cs +++ b/src/SharedKernel/Logging/Middleware/LoggingExtensions.cs @@ -10,7 +10,9 @@ public static class LoggingExtensions public static WebApplication UseRequestLogging(this WebApplication app) { if (Log.Logger.IsEnabled(LogEventLevel.Information)) + { app.UseMiddleware(); + } return app; } @@ -18,7 +20,9 @@ public static WebApplication UseRequestLogging(this WebApplication app) public static WebApplicationBuilder AddOutboundLoggingHandler(this WebApplicationBuilder builder) { if (Log.Logger.IsEnabled(LogEventLevel.Information)) + { builder.Services.AddTransient(); + } return builder; } @@ -26,7 +30,9 @@ public static WebApplicationBuilder AddOutboundLoggingHandler(this WebApplicatio public static IHttpClientBuilder AddOutboundLoggingHandler(this IHttpClientBuilder builder) { if (Log.Logger.IsEnabled(LogEventLevel.Information)) + { builder.AddHttpMessageHandler(); + } return builder; } diff --git a/src/SharedKernel/Logging/Middleware/LoggingOptions.cs b/src/SharedKernel/Logging/Middleware/LoggingOptions.cs index 0593c9a..dd08235 100644 --- a/src/SharedKernel/Logging/Middleware/LoggingOptions.cs +++ b/src/SharedKernel/Logging/Middleware/LoggingOptions.cs @@ -11,31 +11,34 @@ public static class LoggingOptions /// Sensitive keywords to redact in headers and JSON bodies. /// Uses FrozenSet for optimized lookups on static data. /// - public static readonly FrozenSet SensitiveKeywords = new[] - { - "pwd", "pass", "secret", "token", "cookie", "auth", - "pan", "cvv", "cvc", "cardholder", "bindingid", - "ssn", "tin", "iban", "swift", "bankaccount", "notboundcard" - }.ToFrozenSet(StringComparer.OrdinalIgnoreCase); + public static readonly FrozenSet SensitiveKeywords = new HashSet( + [ + "pwd", "pass", "secret", "token", "cookie", "auth", + "pan", "cvv", "cvc", "cardholder", "bindingid", + "ssn", "tin", "iban", "swift", "bankaccount", "notboundcard" + ], + StringComparer.OrdinalIgnoreCase).ToFrozenSet(); /// /// Media type prefixes considered text-like for logging purposes. /// - public static readonly FrozenSet TextLikeMediaPrefixes = new[] - { - "application/json", - "application/x-www-form-urlencoded", - "text/" - }.ToFrozenSet(StringComparer.OrdinalIgnoreCase); + public static readonly FrozenSet TextLikeMediaPrefixes = new HashSet( + [ + "application/json", + "application/x-www-form-urlencoded", + "text/" + ], + StringComparer.OrdinalIgnoreCase).ToFrozenSet(); /// /// Paths to ignore for request logging. /// - public static readonly FrozenSet PathsToIgnore = new[] - { - "/openapi", - "/above-board", - "/favicon.ico", - "/swagger" - }.ToFrozenSet(StringComparer.OrdinalIgnoreCase); + public static readonly FrozenSet PathsToIgnore = new HashSet( + [ + "/openapi", + "/above-board", + "/favicon.ico", + "/swagger" + ], + StringComparer.OrdinalIgnoreCase).ToFrozenSet(); } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/MediaTypeUtil.cs b/src/SharedKernel/Logging/Middleware/MediaTypeUtil.cs index 03a6ab0..f509dab 100644 --- a/src/SharedKernel/Logging/Middleware/MediaTypeUtil.cs +++ b/src/SharedKernel/Logging/Middleware/MediaTypeUtil.cs @@ -7,7 +7,9 @@ internal static class MediaTypeUtil public static string? Normalize(string? contentType) { if (string.IsNullOrWhiteSpace(contentType)) + { return null; + } try { @@ -35,24 +37,34 @@ public static bool IsFormUrlEncoded(string? contentType) => public static bool IsMultipartForm(string? contentType) => Normalize(contentType)?.StartsWith("multipart/form-data", StringComparison.OrdinalIgnoreCase) == true; - public static bool IsFormLike(string? contentType) => - IsFormUrlEncoded(contentType) || IsMultipartForm(contentType); + // Normalizes once instead of delegating to IsFormUrlEncoded + IsMultipartForm (which each normalize separately). + public static bool IsFormLike(string? contentType) + { + var mt = Normalize(contentType); + return string.Equals(mt, "application/x-www-form-urlencoded", StringComparison.OrdinalIgnoreCase) + || mt?.StartsWith("multipart/form-data", StringComparison.OrdinalIgnoreCase) == true; + } public static bool IsTextLike(string? contentType) { var mt = Normalize(contentType); if (string.IsNullOrWhiteSpace(mt)) + { return false; + } - // Check +json suffix + // Catches vendor types like application/vnd.api+json if (mt.EndsWith("+json", StringComparison.OrdinalIgnoreCase)) + { return true; + } - // Check against known text-like prefixes foreach (var prefix in LoggingOptions.TextLikeMediaPrefixes) { if (mt.StartsWith(prefix, StringComparison.OrdinalIgnoreCase)) + { return true; + } } return false; diff --git a/src/SharedKernel/Logging/Middleware/OutboundLoggingHandler.cs b/src/SharedKernel/Logging/Middleware/OutboundLoggingHandler.cs index 1f4f46f..601ede6 100644 --- a/src/SharedKernel/Logging/Middleware/OutboundLoggingHandler.cs +++ b/src/SharedKernel/Logging/Middleware/OutboundLoggingHandler.cs @@ -3,7 +3,7 @@ namespace SharedKernel.Logging.Middleware; -internal sealed class OutboundLoggingHandler(ILogger logger) : DelegatingHandler +internal sealed partial class OutboundLoggingHandler(ILogger logger) : DelegatingHandler { protected override async Task SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) @@ -19,7 +19,17 @@ protected override async Task SendAsync(HttpRequestMessage var (resHeaders, resBody) = await CaptureResponseAsync(response, cancellationToken); - LogHttpOut(request, response, reqHeaders, reqBody, resHeaders, resBody, elapsedMs); + LogHttpOut( + request.Method.Method, + request.RequestUri?.GetLeftPart(UriPartial.Path) ?? "", + (int)response.StatusCode, + elapsedMs, + "HttpOut", + string.IsNullOrEmpty(request.RequestUri?.Query) ? null : request.RequestUri!.Query, + LogFormatting.ToJsonString(reqHeaders), + LogFormatting.ToJsonString(reqBody), + LogFormatting.ToJsonString(resHeaders), + LogFormatting.ToJsonString(resBody)); return response; } @@ -31,58 +41,59 @@ protected override async Task SendAsync(HttpRequestMessage var redactedHeaders = RedactionHelper.RedactHeaders(headerDict); if (request.Content is null) + { return (redactedHeaders, new Dictionary()); + } var mediaType = request.Content.Headers.ContentType?.MediaType; var contentLength = request.Content.Headers.ContentLength; - // MULTIPART: Never enumerate or read - it corrupts internal state - if (request.Content is MultipartFormDataContent) - { - return (redactedHeaders, new Dictionary - { - ["_type"] = "multipart/form-data", - ["_contentLength"] = contentLength, - ["_note"] = "multipart body not captured to preserve request integrity" - }); - } - - // STREAM CONTENT: Not safe to read - would consume the stream - if (request.Content is StreamContent) + switch (request.Content) { - return (redactedHeaders, new Dictionary - { - ["_type"] = mediaType, - ["_contentLength"] = contentLength, - ["_note"] = "stream body not captured to preserve request integrity" - }); + // MULTIPART: Never enumerate or read — it corrupts internal state. + case MultipartFormDataContent: + return (redactedHeaders, new Dictionary + { + ["_type"] = "multipart/form-data", + ["_contentLength"] = contentLength, + ["_note"] = "multipart body not captured to preserve request integrity" + }); + // STREAM CONTENT: Not safe to read — would consume the stream. + case StreamContent: + return (redactedHeaders, new Dictionary + { + ["_type"] = mediaType, + ["_contentLength"] = contentLength, + ["_note"] = "stream body not captured to preserve request integrity" + }); } - // NON-TEXT: Just log metadata if (!MediaTypeUtil.IsTextLike(mediaType)) { return (redactedHeaders, LogFormatting.Omitted("non-text", contentLength, mediaType, LoggingOptions.RequestResponseBodyMaxBytes)); } - // TOO LARGE: Don't read if (contentLength is > LoggingOptions.RequestResponseBodyMaxBytes) { return (redactedHeaders, - LogFormatting.Omitted("exceeds-limit", contentLength, mediaType, LoggingOptions.RequestResponseBodyMaxBytes)); + LogFormatting.Omitted("exceeds-limit", + contentLength, + mediaType, + LoggingOptions.RequestResponseBodyMaxBytes)); } - // SAFE TO READ: ByteArrayContent, StringContent, FormUrlEncodedContent, ReadOnlyMemoryContent - // These are all backed by byte arrays and support multiple reads + // SAFE TO READ: ByteArrayContent, StringContent, FormUrlEncodedContent, ReadOnlyMemoryContent. + // All backed by byte arrays and support multiple reads. var raw = await request.Content.ReadAsStringAsync(ct); - - // Double-check size after reading (in case contentLength was null) + + // Double-check size after reading (in case Content-Length was absent). if (raw.Length > LoggingOptions.RequestResponseBodyMaxBytes) { return (redactedHeaders, LogFormatting.Omitted("exceeds-limit", raw.Length, mediaType, LoggingOptions.RequestResponseBodyMaxBytes)); } - + var body = RedactionHelper.RedactBody(mediaType, raw); return (redactedHeaders, body); } @@ -96,26 +107,27 @@ protected override async Task SendAsync(HttpRequestMessage var mediaType = response.Content.Headers.ContentType?.MediaType; var contentLength = response.Content.Headers.ContentLength; - // Empty response (explicit Content-Length: 0) if (contentLength == 0) + { return (redactedHeaders, new Dictionary()); + } - // Non-text content if (!MediaTypeUtil.IsTextLike(mediaType)) { return (redactedHeaders, LogFormatting.Omitted("non-text", contentLength, mediaType, LoggingOptions.RequestResponseBodyMaxBytes)); } - // Known to be too large if (contentLength > LoggingOptions.RequestResponseBodyMaxBytes) { return (redactedHeaders, - LogFormatting.Omitted("exceeds-limit", contentLength, mediaType, LoggingOptions.RequestResponseBodyMaxBytes)); + LogFormatting.Omitted("exceeds-limit", + contentLength, + mediaType, + LoggingOptions.RequestResponseBodyMaxBytes)); } - // SAFE TO READ: Response bodies are always safe - they've already been received - // This includes chunked responses (no Content-Length header) + // Response bodies are always safe to read — already fully received (includes chunked). return await HttpLogHelper.CaptureAsync( headerDict, () => response.Content.ReadAsStringAsync(ct), @@ -123,37 +135,19 @@ protected override async Task SendAsync(HttpRequestMessage ct); } - private void LogHttpOut(HttpRequestMessage request, - HttpResponseMessage response, - object reqHeaders, - object reqBody, - object resHeaders, - object resBody, - double elapsedMs) - { - var hostPath = request.RequestUri?.GetLeftPart(UriPartial.Path) ?? ""; - - var scope = new Dictionary - { - ["RequestHeaders"] = LogFormatting.ToJsonString(reqHeaders), - ["RequestBody"] = LogFormatting.ToJsonString(reqBody), - ["ResponseHeaders"] = LogFormatting.ToJsonString(resHeaders), - ["ResponseBody"] = LogFormatting.ToJsonString(resBody), - ["ElapsedMs"] = elapsedMs, - ["Kind"] = "HttpOut" - }; - - if (!string.IsNullOrEmpty(request.RequestUri?.Query)) - scope["Query"] = request.RequestUri!.Query; - - using (logger.BeginScope(scope)) - { - logger.LogInformation( - "[HTTP OUT] {Method} {HostPath} -> {StatusCode} in {ElapsedMilliseconds}ms", - request.Method, - hostPath, - (int)response.StatusCode, - elapsedMs); - } - } + // All named placeholders become structured properties in Serilog / Elasticsearch. + // Eliminates the BeginScope dictionary allocation and the LogInformation args-array allocation. + [LoggerMessage(Level = LogLevel.Information, + Message = "[HTTP OUT] {Method} {HostPath} -> {StatusCode} in {ElapsedMs}ms | " + + "{Kind} q={Query} rqH={RequestHeaders} rqB={RequestBody} rsH={ResponseHeaders} rsB={ResponseBody}")] + private partial void LogHttpOut(string method, + string hostPath, + int statusCode, + double elapsedMs, + string kind, + string? query, + string requestHeaders, + string requestBody, + string responseHeaders, + string responseBody); } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/RedactionHelper.cs b/src/SharedKernel/Logging/Middleware/RedactionHelper.cs new file mode 100644 index 0000000..ecdf858 --- /dev/null +++ b/src/SharedKernel/Logging/Middleware/RedactionHelper.cs @@ -0,0 +1,213 @@ +using System.Globalization; +using System.Text; +using System.Text.Json; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.WebUtilities; + +namespace SharedKernel.Logging.Middleware; + +internal static class RedactionHelper +{ + private const string Redacted = "[REDACTED]"; + + public static Dictionary RedactHeaders(IHeaderDictionary headers) => + headers.ToDictionary( + h => h.Key, + h => IsSensitiveKey(h.Key) ? Redacted : h.Value.ToString()); + + public static Dictionary RedactHeaders(Dictionary> headers) => + headers.ToDictionary( + kvp => kvp.Key, + kvp => IsSensitiveKey(kvp.Key) ? Redacted : string.Join(";", kvp.Value)); + + public static object RedactBody(string? contentType, string raw) + { + if (string.IsNullOrWhiteSpace(raw)) + { + return new Dictionary(); + } + + if (MediaTypeUtil.IsJson(contentType)) + { + return RedactJsonBody(raw); + } + + if (MediaTypeUtil.IsFormUrlEncoded(contentType)) + { + return RedactFormUrlEncodedBody(raw); + } + + return RedactPlainTextBody(raw); + } + + private static object RedactJsonBody(string raw) + { + try + { + var element = JsonSerializer.Deserialize(raw); + return RedactElement(element); + } + catch (JsonException) + { + return new Dictionary { ["invalidJson"] = true }; + } + } + + private static Dictionary RedactFormUrlEncodedBody(string raw) + { + var dict = new Dictionary(StringComparer.OrdinalIgnoreCase); + var parsed = QueryHelpers.ParseQuery("?" + raw); + + foreach (var kvp in parsed) + { + if (string.IsNullOrEmpty(kvp.Key)) + { + continue; + } + + var joined = string.Join(";", kvp.Value.ToArray()); + dict[kvp.Key] = RedactFormValue(kvp.Key, joined); + } + + return dict; + } + + private static Dictionary RedactPlainTextBody(string raw) + { + var rawBytes = Encoding.UTF8.GetByteCount(raw); + + if (rawBytes > LoggingOptions.RedactionMaxPropertyBytes) + { + return new Dictionary + { + ["text"] = $"[OMITTED: exceeds-limit ~{rawBytes / 1024}KB]" + }; + } + + var value = ContainsSensitiveKeyword(raw) ? Redacted : raw; + return new Dictionary { ["text"] = value }; + } + + public static Dictionary RedactFormFields(IFormCollection form) + { + var fields = new Dictionary(StringComparer.OrdinalIgnoreCase); + + foreach (var kvp in form) + { + var raw = string.Join(";", kvp.Value.ToArray()); + fields[kvp.Key] = RedactFormValue(kvp.Key, raw); + } + + AddFilePlaceholders(form.Files, fields); + + return fields; + } + + private static void AddFilePlaceholders(IFormFileCollection files, Dictionary fields) + { + if (files.Count == 0) + { + return; + } + + var counts = new Dictionary(StringComparer.OrdinalIgnoreCase); + var sizes = new Dictionary(StringComparer.OrdinalIgnoreCase); + + foreach (var file in files) + { + var key = file.Name; + counts.TryGetValue(key, out var count); + counts[key] = count + 1; + + sizes.TryGetValue(key, out var bytes); + sizes[key] = bytes + file.Length; + } + + foreach (var key in counts.Keys) + { + var count = counts[key]; + var sizeKb = (int)Math.Round(sizes[key] / 1024d); + + var placeholder = count == 1 + ? $"[OMITTED: file {sizeKb}KB]" + : $"[OMITTED: {count} files {sizeKb}KB]"; + + if (fields.TryGetValue(key, out var existing) && !string.IsNullOrWhiteSpace(existing)) + { + fields[key] = $"{existing}; {placeholder}"; + } + else + { + fields[key] = placeholder; + } + } + } + + internal static string RedactFormValue(string key, string value) + { + if (IsSensitiveKey(key) || ContainsSensitiveKeyword(value)) + { + return Redacted; + } + + var bytes = Encoding.UTF8.GetByteCount(value); + return bytes > LoggingOptions.RedactionMaxPropertyBytes + ? $"[OMITTED: exceeds-limit ~{bytes / 1024}KB]" + : value; + } + + private static object RedactElement(JsonElement element) => element.ValueKind switch + { + JsonValueKind.Object => RedactJsonObject(element), + JsonValueKind.Array => element.EnumerateArray().Select(RedactElement).ToArray(), + JsonValueKind.String => RedactString(element.GetString()!), + JsonValueKind.Number => ParseJsonNumber(element), + JsonValueKind.True => true, + JsonValueKind.False => false, + JsonValueKind.Null => null!, + _ => element.GetRawText() + }; + + private static Dictionary RedactJsonObject(JsonElement element) => + element.EnumerateObject().ToDictionary( + p => p.Name, + p => IsSensitiveKey(p.Name) ? (object?)Redacted : RedactElement(p.Value)); + + private static object ParseJsonNumber(JsonElement element) + { + if (element.TryGetInt64(out var i)) + { + return i; + } + + if (element.TryGetDouble(out var d)) + { + return d; + } + + if (decimal.TryParse(element.GetRawText(), NumberStyles.Any, CultureInfo.InvariantCulture, out var m)) + { + return m; + } + + return element.GetRawText(); + } + + private static string RedactString(string value) + { + var bytes = Encoding.UTF8.GetByteCount(value); + + if (bytes > LoggingOptions.RedactionMaxPropertyBytes) + { + return $"[OMITTED: exceeds-limit ~{bytes / 1024}KB]"; + } + + return ContainsSensitiveKeyword(value) ? Redacted : value; + } + + private static bool IsSensitiveKey(string key) => + LoggingOptions.SensitiveKeywords.Any(k => key.Contains(k, StringComparison.OrdinalIgnoreCase)); + + private static bool ContainsSensitiveKeyword(string value) => + LoggingOptions.SensitiveKeywords.Any(k => value.Contains(k, StringComparison.OrdinalIgnoreCase)); +} \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/ReductionHelper.cs b/src/SharedKernel/Logging/Middleware/ReductionHelper.cs deleted file mode 100644 index 13adcc8..0000000 --- a/src/SharedKernel/Logging/Middleware/ReductionHelper.cs +++ /dev/null @@ -1,194 +0,0 @@ -using System.Globalization; -using System.Text; -using System.Text.Json; -using Microsoft.AspNetCore.Http; -using Microsoft.AspNetCore.WebUtilities; - -namespace SharedKernel.Logging.Middleware; - -internal static class RedactionHelper -{ - private const string Redacted = "[REDACTED]"; - - public static Dictionary RedactHeaders(IHeaderDictionary headers) => - headers.ToDictionary( - h => h.Key, - h => IsSensitiveKey(h.Key) ? Redacted : h.Value.ToString()); - - public static Dictionary RedactHeaders(Dictionary> headers) => - headers.ToDictionary( - kvp => kvp.Key, - kvp => IsSensitiveKey(kvp.Key) ? Redacted : string.Join(";", kvp.Value)); - - - public static object RedactBody(string? contentType, string raw) - { - if (string.IsNullOrWhiteSpace(raw)) - return new Dictionary(); - - // JSON (including +json) - if (MediaTypeUtil.IsJson(contentType)) - return RedactJsonBody(raw); - - // application/x-www-form-urlencoded - if (MediaTypeUtil.IsFormUrlEncoded(contentType)) - return RedactFormUrlEncodedBody(raw); - - // Plain text fallback - return RedactPlainTextBody(raw); - } - - private static object RedactJsonBody(string raw) - { - try - { - var element = JsonSerializer.Deserialize(raw); - return RedactElement(element); - } - catch (JsonException) - { - return new Dictionary { ["invalidJson"] = true }; - } - } - - private static Dictionary RedactFormUrlEncodedBody(string raw) - { - var dict = new Dictionary(StringComparer.OrdinalIgnoreCase); - var parsed = QueryHelpers.ParseQuery("?" + raw); - - foreach (var kvp in parsed) - { - if (string.IsNullOrEmpty(kvp.Key)) - continue; - - var joined = string.Join(";", kvp.Value.ToArray()); - dict[kvp.Key] = RedactFormValue(kvp.Key, joined); - } - - return dict; - } - - private static Dictionary RedactPlainTextBody(string raw) - { - var rawBytes = Encoding.UTF8.GetByteCount(raw); - - if (rawBytes > LoggingOptions.RedactionMaxPropertyBytes) - { - return new Dictionary - { - ["text"] = $"[OMITTED: exceeds-limit ~{rawBytes / 1024}KB]" - }; - } - - var value = ContainsSensitiveKeyword(raw) ? Redacted : raw; - return new Dictionary { ["text"] = value }; - } - - - public static Dictionary RedactFormFields(IFormCollection form) - { - var fields = new Dictionary(StringComparer.OrdinalIgnoreCase); - - // Text fields - foreach (var kvp in form) - { - var raw = string.Join(";", kvp.Value.ToArray()); - fields[kvp.Key] = RedactFormValue(kvp.Key, raw); - } - - // File placeholders - AddFilePlaceholders(form.Files, fields); - - return fields; - } - - private static void AddFilePlaceholders(IFormFileCollection files, Dictionary fields) - { - if (files.Count == 0) - return; - - var counts = new Dictionary(StringComparer.OrdinalIgnoreCase); - var sizes = new Dictionary(StringComparer.OrdinalIgnoreCase); - - foreach (var file in files) - { - var key = file.Name; - counts.TryGetValue(key, out var count); - counts[key] = count + 1; - - sizes.TryGetValue(key, out var bytes); - sizes[key] = bytes + file.Length; - } - - foreach (var key in counts.Keys) - { - var count = counts[key]; - var sizeKb = (int)Math.Round(sizes[key] / 1024d); - - var placeholder = count == 1 - ? $"[OMITTED: file {sizeKb}KB]" - : $"[OMITTED: {count} files {sizeKb}KB]"; - - if (fields.TryGetValue(key, out var existing) && !string.IsNullOrWhiteSpace(existing)) - fields[key] = $"{existing}; {placeholder}"; - else - fields[key] = placeholder; - } - } - - internal static string RedactFormValue(string key, string value) - { - if (IsSensitiveKey(key) || ContainsSensitiveKeyword(value)) - return Redacted; - - var bytes = Encoding.UTF8.GetByteCount(value); - return bytes > LoggingOptions.RedactionMaxPropertyBytes - ? $"[OMITTED: exceeds-limit ~{bytes / 1024}KB]" - : value; - } - - private static object RedactElement(JsonElement element) => element.ValueKind switch - { - JsonValueKind.Object => RedactJsonObject(element), - JsonValueKind.Array => element.EnumerateArray().Select(RedactElement).ToArray(), - JsonValueKind.String => RedactString(element.GetString()!), - JsonValueKind.Number => ParseJsonNumber(element), - JsonValueKind.True => true, - JsonValueKind.False => false, - JsonValueKind.Null => null!, - _ => element.GetRawText() - }; - - private static Dictionary RedactJsonObject(JsonElement element) => - element.EnumerateObject().ToDictionary( - p => p.Name, - p => IsSensitiveKey(p.Name) ? (object?)Redacted : RedactElement(p.Value)); - - private static object ParseJsonNumber(JsonElement element) - { - if (element.TryGetInt64(out var i)) - return i; - if (element.TryGetDouble(out var d)) - return d; - if (decimal.TryParse(element.GetRawText(), NumberStyles.Any, CultureInfo.InvariantCulture, out var m)) - return m; - return element.GetRawText(); - } - - private static string RedactString(string value) - { - var bytes = Encoding.UTF8.GetByteCount(value); - - if (bytes > LoggingOptions.RedactionMaxPropertyBytes) - return $"[OMITTED: exceeds-limit ~{bytes / 1024}KB]"; - - return ContainsSensitiveKeyword(value) ? Redacted : value; - } - - - private static bool IsSensitiveKey(string key) => - LoggingOptions.SensitiveKeywords.Any(k => key.Contains(k, StringComparison.OrdinalIgnoreCase)); - - private static bool ContainsSensitiveKeyword(string value) => - LoggingOptions.SensitiveKeywords.Any(k => value.Contains(k, StringComparison.OrdinalIgnoreCase)); -} \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/RequestLoggingMiddleware.cs b/src/SharedKernel/Logging/Middleware/RequestLoggingMiddleware.cs index cf947aa..8a35c58 100644 --- a/src/SharedKernel/Logging/Middleware/RequestLoggingMiddleware.cs +++ b/src/SharedKernel/Logging/Middleware/RequestLoggingMiddleware.cs @@ -1,14 +1,14 @@ using System.Diagnostics; +using System.Runtime.InteropServices; using Microsoft.AspNetCore.Http; using Microsoft.Extensions.Logging; namespace SharedKernel.Logging.Middleware; -internal sealed class RequestLoggingMiddleware(RequestDelegate next, ILogger logger) +internal sealed partial class RequestLoggingMiddleware(RequestDelegate next, ILogger logger) { public async Task InvokeAsync(HttpContext context) { - // Skip OPTIONS requests and ignored paths if (HttpMethods.IsOptions(context.Request.Method) || ShouldIgnorePath(context.Request.Path)) { await next(context); @@ -29,13 +29,22 @@ public async Task InvokeAsync(HttpContext context) } finally { - var elapsedMs = Stopwatch.GetElapsedTime(timestamp) - .TotalMilliseconds; + var elapsedMs = Stopwatch.GetElapsedTime(timestamp).TotalMilliseconds; var (resHeaders, resBody) = await CaptureResponseAsync(context, tee); context.Response.Body = originalBody; - LogHttpIn(context, reqHeaders, reqBody, resHeaders, resBody, elapsedMs); + LogHttpIn( + context.Request.Method, + context.Request.Path.Value, + context.Response.StatusCode, + elapsedMs, + "HttpIn", + context.Request.QueryString.HasValue ? context.Request.QueryString.Value : null, + LogFormatting.ToJsonString(reqHeaders), + LogFormatting.ToJsonString(reqBody), + LogFormatting.ToJsonString(resHeaders), + LogFormatting.ToJsonString(resBody)); } } @@ -50,16 +59,16 @@ private static bool ShouldIgnorePath(PathString path) => var contentLength = request.ContentLength; var redactedHeaders = RedactionHelper.RedactHeaders(request.Headers); - // Empty body detection var looksEmpty = contentLength == 0 || (!contentLength.HasValue && string.IsNullOrWhiteSpace(normalizedContentType) && !request.Headers.ContainsKey("Transfer-Encoding")); if (looksEmpty) + { return (redactedHeaders, new Dictionary()); + } - // Form content (x-www-form-urlencoded or multipart/form-data) if (MediaTypeUtil.IsFormLike(normalizedContentType)) { if (contentLength is null or > LoggingOptions.RequestResponseBodyMaxBytes) @@ -75,7 +84,6 @@ private static bool ShouldIgnorePath(PathString path) => return (redactedHeaders, RedactionHelper.RedactFormFields(form)); } - // Text-like content within size limits if (!MediaTypeUtil.IsTextLike(normalizedContentType) || contentLength is not <= LoggingOptions.RequestResponseBodyMaxBytes) { @@ -92,8 +100,6 @@ private static bool ShouldIgnorePath(PathString path) => request.Headers, normalizedContentType, ct); - - // Non-text or large content } private static async Task<(object Headers, object Body)> CaptureResponseAsync(HttpContext context, @@ -104,22 +110,29 @@ private static bool ShouldIgnorePath(PathString path) => var isText = MediaTypeUtil.IsTextLike(responseContentType); var redactedHeaders = RedactionHelper.RedactHeaders(context.Response.Headers); - // Empty response if (tee.TotalWritten == 0) + { return (redactedHeaders, new Dictionary()); + } - // Text response within size limits if (isText && tee.TotalWritten <= LoggingOptions.RequestResponseBodyMaxBytes) { - using var memoryStream = new MemoryStream(tee.Captured.ToArray()); - return await HttpLogHelper.CaptureAsync( - memoryStream, - context.Response.Headers, - responseContentType, - ct); + // MemoryMarshal avoids the extra heap copy that tee.Captured.ToArray() would incur. + // TryGetArray always succeeds here since Captured is backed by an ArrayPool byte[]. + Stream memoryStream = MemoryMarshal.TryGetArray(tee.Captured, out var seg) + ? new MemoryStream(seg.Array!, seg.Offset, seg.Count, writable: false) + : new MemoryStream(tee.Captured.ToArray()); + + await using (memoryStream) + { + return await HttpLogHelper.CaptureAsync( + memoryStream, + context.Response.Headers, + responseContentType, + ct); + } } - // Non-text or large response var reason = isText ? "exceeds-limit" : "non-text"; return (redactedHeaders, LogFormatting.Omitted( reason, @@ -128,35 +141,20 @@ private static bool ShouldIgnorePath(PathString path) => LoggingOptions.RequestResponseBodyMaxBytes)); } - private void LogHttpIn(HttpContext context, - object reqHeaders, - object reqBody, - object resHeaders, - object resBody, - double elapsedMs) - { - // Convert bodies to JSON strings to prevent Elasticsearch field explosion - var scope = new Dictionary - { - ["RequestHeaders"] = LogFormatting.ToJsonString(reqHeaders), - ["RequestBody"] = LogFormatting.ToJsonString(reqBody), - ["ResponseHeaders"] = LogFormatting.ToJsonString(resHeaders), - ["ResponseBody"] = LogFormatting.ToJsonString(resBody), - ["ElapsedMs"] = elapsedMs, - ["Kind"] = "HttpIn" - }; - - if (context.Request.QueryString.HasValue) - scope["Query"] = context.Request.QueryString.Value; - - using (logger.BeginScope(scope)) - { - logger.LogInformation( - "[HTTP IN] {Method} {Path} -> {StatusCode} in {ElapsedMilliseconds}ms", - context.Request.Method, - context.Request.Path.Value, - context.Response.StatusCode, - elapsedMs); - } - } + // All named placeholders become structured properties in Serilog / Elasticsearch. + // Eliminates the BeginScope dictionary allocation and the LogInformation args-array allocation. + [LoggerMessage(Level = LogLevel.Information, + Message = "[HTTP IN] {Method} {Path} -> {StatusCode} in {ElapsedMs}ms | " + + "{Kind} q={Query} rqH={RequestHeaders} rqB={RequestBody} rsH={ResponseHeaders} rsB={ResponseBody}")] + private partial void LogHttpIn( + string method, + string? path, + int statusCode, + double elapsedMs, + string kind, + string? query, + string requestHeaders, + string requestBody, + string responseHeaders, + string responseBody); } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/SignalRLoggingHubFilter.cs b/src/SharedKernel/Logging/Middleware/SignalRLoggingHubFilter.cs index 7f414b7..ae443b3 100644 --- a/src/SharedKernel/Logging/Middleware/SignalRLoggingHubFilter.cs +++ b/src/SharedKernel/Logging/Middleware/SignalRLoggingHubFilter.cs @@ -5,98 +5,78 @@ namespace SharedKernel.Logging.Middleware; -internal sealed class SignalRLoggingHubFilter(ILogger logger) : IHubFilter +internal sealed partial class SignalRLoggingHubFilter(ILogger logger) : IHubFilter { - public async ValueTask InvokeMethodAsync( - HubInvocationContext invocationContext, - Func> next) - { - var timestamp = Stopwatch.GetTimestamp(); + public async ValueTask InvokeMethodAsync( + HubInvocationContext invocationContext, + Func> next) + { + var timestamp = Stopwatch.GetTimestamp(); - var hubName = invocationContext.Hub.GetType().Name; - var connectionId = invocationContext.Context.ConnectionId; - var userId = invocationContext.Context.UserIdentifier; - var methodName = invocationContext.HubMethodName; + var hubName = invocationContext.Hub.GetType().Name; + var methodName = invocationContext.HubMethodName; + var connectionId = invocationContext.Context.ConnectionId; + var userId = invocationContext.Context.UserIdentifier; - // Serialize and redact arguments - var rawArgsJson = JsonSerializer.Serialize(invocationContext.HubMethodArguments); - var redactedArgs = RedactionHelper.RedactBody("application/json", rawArgsJson); + var rawArgsJson = JsonSerializer.Serialize(invocationContext.HubMethodArguments); + var redactedArgs = RedactionHelper.RedactBody("application/json", rawArgsJson); - var result = await next(invocationContext); + var result = await next(invocationContext); - var elapsedMs = Stopwatch.GetElapsedTime(timestamp).TotalMilliseconds; + var elapsedMs = Stopwatch.GetElapsedTime(timestamp).TotalMilliseconds; - // Convert to JSON string to prevent Elasticsearch field explosion - var scope = new Dictionary - { - ["Args"] = LogFormatting.ToJsonString(redactedArgs), - ["Hub"] = hubName, - ["ConnId"] = connectionId, - ["UserId"] = userId, - ["ElapsedMs"] = elapsedMs, - ["Kind"] = "SignalR" - }; + LogInvoke(hubName, methodName, elapsedMs, "SignalR", connectionId, userId, LogFormatting.ToJsonString(redactedArgs)); - using (logger.BeginScope(scope)) - { - logger.LogInformation( - "[SignalR] {Hub}.{Method} completed in {ElapsedMilliseconds}ms", - hubName, - methodName, - elapsedMs); - } + return result; + } - return result; - } + public async Task OnConnectedAsync(HubLifetimeContext context, Func next) + { + var (hub, connId, userId) = ExtractContext(context); + LogConnected(hub, "SignalR", connId, userId); + await next(context); + } - public async Task OnConnectedAsync(HubLifetimeContext context, Func next) - { - var hubName = context.Hub.GetType().Name; - var connectionId = context.Context.ConnectionId; - var userId = context.Context.UserIdentifier; + public async Task OnDisconnectedAsync( + HubLifetimeContext context, + Exception? exception, + Func next) + { + var (hub, connId, userId) = ExtractContext(context); + LogDisconnected(hub, "SignalR", connId, userId); + await next(context, exception); + } - using (logger.BeginScope(new Dictionary - { - ["Hub"] = hubName, - ["ConnId"] = connectionId, - ["UserId"] = userId, - ["Kind"] = "SignalR" - })) - { - logger.LogInformation( - "[Connected] SignalR {Hub}, ConnId={ConnId}, UserId={UserId} connected.", - hubName, - connectionId, - userId); - } + private static (string Hub, string? ConnId, string? UserId) ExtractContext(HubLifetimeContext ctx) => + (ctx.Hub.GetType().Name, ctx.Context.ConnectionId, ctx.Context.UserIdentifier); - await next(context); - } + // All named placeholders become structured properties in Serilog / Elasticsearch. + // Eliminates the BeginScope dictionary allocation and the LogInformation args-array allocation. - public async Task OnDisconnectedAsync( - HubLifetimeContext context, - Exception? exception, - Func next) - { - var hubName = context.Hub.GetType().Name; - var connectionId = context.Context.ConnectionId; - var userId = context.Context.UserIdentifier; + [LoggerMessage(Level = LogLevel.Information, + Message = "[SignalR] {Hub}.{HubMethod} completed in {ElapsedMs}ms | {Kind} connId={ConnId} userId={UserId} args={Args}")] + private partial void LogInvoke( + string hub, + string hubMethod, + double elapsedMs, + string kind, + string? connId, + string? userId, + string args); - using (logger.BeginScope(new Dictionary - { - ["Hub"] = hubName, - ["ConnId"] = connectionId, - ["UserId"] = userId, - ["Kind"] = "SignalR" - })) - { - logger.LogInformation( - "[Disconnected] SignalR {Hub}, ConnId={ConnId}, UserId={UserId} disconnected gracefully.", - hubName, - connectionId, - userId); - } + [LoggerMessage(Level = LogLevel.Information, + Message = "[Connected] SignalR {Hub} | {Kind} connId={ConnId} userId={UserId}")] + private partial void LogConnected( + string hub, + string kind, + string? connId, + string? userId); - await next(context, exception); - } + [LoggerMessage(Level = LogLevel.Information, + Message = "[Disconnected] SignalR {Hub} | {Kind} connId={ConnId} userId={UserId}")] + private partial void LogDisconnected( + string hub, + string kind, + string? connId, + string? userId); } \ No newline at end of file diff --git a/src/SharedKernel/SharedKernel.csproj b/src/SharedKernel/SharedKernel.csproj index aab8967..901cb2b 100644 --- a/src/SharedKernel/SharedKernel.csproj +++ b/src/SharedKernel/SharedKernel.csproj @@ -21,8 +21,8 @@ pandatech.png README.md - 2.2.0 - Refactored documentations, updated nugets + 2.2.1 + Request and Response logging modernized and has extreme perf boost for logging true true