From 724892615de670258d8dd37eb4e3f270e0b762ca Mon Sep 17 00:00:00 2001 From: HaikAsatryan Date: Tue, 21 Jan 2025 16:47:14 +0400 Subject: [PATCH] request logging optimization and new httpclienthandler addition --- Readme.md | 44 ++++- Shared.Kernel.Demo/Program.cs | 23 ++- Shared.Kernel.Demo/Shared.Kernel.Demo.csproj | 2 +- src/SharedKernel/Logging/LoggingExtensions.cs | 18 +- .../Logging/OutboundLoggingHandler.cs | 90 +++++++++ src/SharedKernel/Logging/ReductionHelper.cs | 144 ++++++++++++++ .../Logging/RequestLoggingMiddleware.cs | 85 +++++++++ .../RequestResponseLoggingMiddleware.cs | 178 ------------------ src/SharedKernel/SharedKernel.csproj | 20 +- .../SharedKernel.Tests.csproj | 6 +- 10 files changed, 407 insertions(+), 203 deletions(-) create mode 100644 src/SharedKernel/Logging/OutboundLoggingHandler.cs create mode 100644 src/SharedKernel/Logging/ReductionHelper.cs create mode 100644 src/SharedKernel/Logging/RequestLoggingMiddleware.cs delete mode 100644 src/SharedKernel/Logging/RequestResponseLoggingMiddleware.cs diff --git a/Readme.md b/Readme.md index 1a3c8ee..6a9fb92 100644 --- a/Readme.md +++ b/Readme.md @@ -147,7 +147,7 @@ builder var app = builder.Build(); app - .UseRequestResponseLogging() + .UseRequestLogging() .UseResponseCrafter() .UseCors() .MapMinimalApis() @@ -253,7 +253,8 @@ Add the following configuration to your `appsettings.json` file: Based on the above configuration, the UI will be accessible at the following URLs: - **Swagger (all documents):** [http://localhost/swagger](http://localhost/swagger) -- **Swagger (external document only):** [http://localhost/swagger/integration-v1](http://localhost/swagger/integration-v1) +- **Swagger (external document only): + ** [http://localhost/swagger/integration-v1](http://localhost/swagger/integration-v1) - **Scalar (admin document):** [http://localhost/scalar/admin-v1](http://localhost/scalar/admin-v1) - **Scalar (integration document):** [http://localhost/scalar/integration-v1](http://localhost/scalar/integration-v1) @@ -266,9 +267,8 @@ Based on the above configuration, the UI will be accessible at the following URL Development, Production). - **Elastic Common Schema Formatting:** Logs are formatted using the Elastic Common Schema (ECS) for compatibility with Elasticsearch. -- **Request and Response Logging Middleware:** Middleware that logs incoming requests and outgoing responses while - redacting - sensitive information. +- **Request Logging Middleware:** Middleware that logs incoming requests and outgoing responses while redacting + sensitive information and 5kb exceeding properties. - **Log Filtering:** Excludes unwanted logs from Hangfire Dashboard, Swagger, and outbox database commands. - **Distributed:** Designed to work with distributed systems and microservices. @@ -285,7 +285,7 @@ In your middleware pipeline, add the request and response logging middleware: ```csharp var app = builder.Build(); -app.UseRequestResponseLogging(); +app.UseRequestLogging(); ``` In your `appsettings.{Environment}.json` configure `Serilog`. @@ -337,12 +337,39 @@ builder.LogStartAttempt(); // Configure services var app = builder.Build(); // Configure middleware -app.UseRequestResponseLogging(); +app.UseRequestLogging(); // Other middleware app.LogStartSuccess(); app.Run(); ``` +### Outbound Logging with HttpClient + +In addition to the `RequestLoggingMiddleware` for inbound requests, you can now log **outbound** HTTP calls via an +`OutboundLoggingHandler`. This handler captures request and response data (including headers and bodies), automatically +redacting sensitive information (e.g., passwords, tokens). + +#### Usage + +1. **Register the handler** in your `WebApplicationBuilder`: + ```csharp + builder.AddOutboundLoggingHandler(); + ``` +2. **Attach** the handler to any HttpClient registration: + ```csharp + builder.Services + .AddHttpClient("RandomApiClient", client => + { + client.BaseAddress = new Uri("http://localhost"); + }) + .AddOutboundLoggingHandler(); + ``` +3. **Check logs:** Outbound requests and responses are now logged with redacted headers and bodies, just like inbound + traffic. + +> Note: The same redaction rules apply to inbound and outbound calls. Update RedactionHelper if you need to modify the +> behavior (e.g., adding new sensitive keywords). + ## MediatR and FluentValidation Integration ### Key Features @@ -543,7 +570,8 @@ Integrate OpenTelemetry for observability, including metrics, traces, and loggin - Health Metrics: `url/above-board/prometheus/health` 3. OTLP Configuration: - To configure the OTLP exporter, ensure the following entries are present in your appsettings{Environment}.json or as environment variables: + To configure the OTLP exporter, ensure the following entries are present in your appsettings{Environment}.json or as + environment variables: ```json { "OTEL_EXPORTER_OTLP_ENDPOINT": "http://localhost:4317" diff --git a/Shared.Kernel.Demo/Program.cs b/Shared.Kernel.Demo/Program.cs index 7b58ee8..56a14fe 100644 --- a/Shared.Kernel.Demo/Program.cs +++ b/Shared.Kernel.Demo/Program.cs @@ -29,13 +29,23 @@ //.AddDistributedSignalR("DistributedSignalR") // or .AddSignalR() .MapDefaultTimeZone() .AddCors() + .AddOutboundLoggingHandler() .AddHealthChecks(); +builder.Services + .AddHttpClient("RandomApiClient", + client => + { + client.BaseAddress = new Uri("http://localhost"); + }) + .AddOutboundLoggingHandler(); + + var app = builder.Build(); app - .UseRequestResponseLogging() + .UseRequestLogging() .UseResponseCrafter() .UseCors() .MapMinimalApis() @@ -49,6 +59,17 @@ app.MapPost("/params", ([AsParameters] TestTypes testTypes) => TypedResults.Ok(testTypes)); app.MapPost("/body", ([FromBody] TestTypes testTypes) => TypedResults.Ok(testTypes)); +app.MapGet("/hello", () => TypedResults.Ok("Hello World!")); + +app.MapGet("/get-data", + async (IHttpClientFactory httpClientFactory) => + { + var httpClient = httpClientFactory.CreateClient("RandomApiClient"); + httpClient.DefaultRequestHeaders.Add("auth", "hardcoded-auth-value"); + var response = await httpClient.GetFromJsonAsync("hello"); + + return response; + }); app.LogStartSuccess(); diff --git a/Shared.Kernel.Demo/Shared.Kernel.Demo.csproj b/Shared.Kernel.Demo/Shared.Kernel.Demo.csproj index 0da48ae..23d8d87 100644 --- a/Shared.Kernel.Demo/Shared.Kernel.Demo.csproj +++ b/Shared.Kernel.Demo/Shared.Kernel.Demo.csproj @@ -7,7 +7,7 @@ - + diff --git a/src/SharedKernel/Logging/LoggingExtensions.cs b/src/SharedKernel/Logging/LoggingExtensions.cs index 3a7c952..d7074fd 100644 --- a/src/SharedKernel/Logging/LoggingExtensions.cs +++ b/src/SharedKernel/Logging/LoggingExtensions.cs @@ -1,17 +1,31 @@ using Microsoft.AspNetCore.Builder; +using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Logging; namespace SharedKernel.Logging; public static class LoggingExtensions { - public static WebApplication UseRequestResponseLogging(this WebApplication app) + public static WebApplication UseRequestLogging(this WebApplication app) { if (app.Logger.IsEnabled(LogLevel.Information)) { - app.UseMiddleware(); + app.UseMiddleware(); } return app; } + + public static WebApplicationBuilder AddOutboundLoggingHandler(this WebApplicationBuilder builder) + { + builder.Services.AddTransient(); + + return builder; + } + + public static IHttpClientBuilder AddOutboundLoggingHandler(this IHttpClientBuilder builder) + { + builder.AddHttpMessageHandler(); + return builder; + } } \ No newline at end of file diff --git a/src/SharedKernel/Logging/OutboundLoggingHandler.cs b/src/SharedKernel/Logging/OutboundLoggingHandler.cs new file mode 100644 index 0000000..25940df --- /dev/null +++ b/src/SharedKernel/Logging/OutboundLoggingHandler.cs @@ -0,0 +1,90 @@ +using System.Diagnostics; +using System.Text.Json; +using Microsoft.Extensions.Logging; + +namespace SharedKernel.Logging; + +internal sealed class OutboundLoggingHandler(ILogger logger) : DelegatingHandler +{ + protected override async Task SendAsync(HttpRequestMessage request, + CancellationToken cancellationToken) + { + var stopwatch = Stopwatch.GetTimestamp(); + + // Capture request + var requestHeadersDict = CreateHeadersDictionary(request); + + var requestHeaders = RedactionHelper.RedactHeaders(requestHeadersDict); + + var requestBodyRaw = request.Content == null + ? string.Empty + : await request.Content.ReadAsStringAsync(cancellationToken); + var requestBody = JsonSerializer.Serialize(RedactionHelper.ParseAndRedactJson(requestBodyRaw)); + + var response = await base.SendAsync(request, cancellationToken); + + // Capture response + var elapsedMs = Stopwatch.GetElapsedTime(stopwatch) + .TotalMilliseconds; + + var responseHeadersDict = CreateHeadersDictionary(response); + var responseHeaders = RedactionHelper.RedactHeaders(responseHeadersDict); + + var responseBodyRaw = await response.Content.ReadAsStringAsync(cancellationToken); + var responseBody = JsonSerializer.Serialize(RedactionHelper.ParseAndRedactJson(responseBodyRaw)); + + // Log everything + logger.LogInformation( + "[Outbound Call] HTTP {Method} to {Uri} responded with {StatusCode} in {ElapsedMs}ms. " + + "Request Headers: {RequestHeaders}, Request Body: {RequestBody}, " + + "Response Headers: {ResponseHeaders}, Response Body: {ResponseBody}", + request.Method, + request.RequestUri, + (int)response.StatusCode, + elapsedMs, + JsonSerializer.Serialize(requestHeaders), + requestBody, + JsonSerializer.Serialize(responseHeaders), + responseBody); + + return response; + } + + private static Dictionary> CreateHeadersDictionary(HttpRequestMessage request) + { + var dict = new Dictionary>(StringComparer.OrdinalIgnoreCase); + + // Request-wide headers + foreach (var h in request.Headers) + dict[h.Key] = h.Value; + + // Content headers + if (request.Content?.Headers == null) + { + return dict; + } + + + foreach (var h in request.Content.Headers) + dict[h.Key] = h.Value; + + + return dict; + } + + private static Dictionary> CreateHeadersDictionary(HttpResponseMessage response) + { + var dict = new Dictionary>(StringComparer.OrdinalIgnoreCase); + + // Response-wide headers + foreach (var h in response.Headers) + dict[h.Key] = h.Value; + + + foreach (var h in response.Content.Headers) + dict[h.Key] = h.Value; + + + return dict; + } +} \ No newline at end of file diff --git a/src/SharedKernel/Logging/ReductionHelper.cs b/src/SharedKernel/Logging/ReductionHelper.cs new file mode 100644 index 0000000..3c4e70b --- /dev/null +++ b/src/SharedKernel/Logging/ReductionHelper.cs @@ -0,0 +1,144 @@ +using System.Text.Json; +using Microsoft.AspNetCore.Http; + +namespace SharedKernel.Logging; + +internal static class RedactionHelper +{ + private const int MaxPropertyLength = 1024 * 5; // 5KB + + private static readonly HashSet SensitiveKeywords = new(StringComparer.OrdinalIgnoreCase) + { + "pwd", + "pass", + "secret", + "token", + "cookie", + "auth" + }; + + // ------------------------------------------------- + // Public Redaction APIs for Headers + // ------------------------------------------------- + + // For ASP.NET Core request/response headers: + public static Dictionary RedactHeaders(IHeaderDictionary headers) + { + var result = new Dictionary(StringComparer.OrdinalIgnoreCase); + foreach (var header in headers) + { + var key = header.Key; + var value = SensitiveKeywords.Any(k => key.Contains(k, StringComparison.OrdinalIgnoreCase)) + ? "[REDACTED]" + : header.Value.ToString(); + + result[key] = value; + } + + return result; + } + + // For outbound HTTP requests/responses with a dictionary of values: + public static Dictionary RedactHeaders(Dictionary> headers) + { + var result = new Dictionary(StringComparer.OrdinalIgnoreCase); + foreach (var kvp in headers) + { + var key = kvp.Key; + var joinedValue = string.Join(";", kvp.Value); + + result[key] = SensitiveKeywords.Any(k => key.Contains(k, StringComparison.OrdinalIgnoreCase)) + ? "[REDACTED]" + : joinedValue; + } + + return result; + } + + // ------------------------------------------------- + // Public Redaction APIs for Bodies + // ------------------------------------------------- + + public static object ParseAndRedactJson(string body) + { + if (string.IsNullOrWhiteSpace(body)) + return string.Empty; + + try + { + var jsonElement = JsonSerializer.Deserialize(body); + return RedactSensitiveData(jsonElement); + } + catch (JsonException) + { + // If invalid JSON, do naive string-based redaction + return RedactSensitiveString(body); + } + } + + // ------------------------------------------------- + // Internal Implementation Details + // ------------------------------------------------- + + private static object RedactSensitiveData(JsonElement element) + { + return element.ValueKind switch + { + JsonValueKind.Object => RedactObject(element), + JsonValueKind.Array => element.EnumerateArray() + .Select(RedactSensitiveData) + .ToArray(), + JsonValueKind.String => RedactSensitiveString(element.GetString()), + _ => element.GetRawText() + }; + } + + private static Dictionary RedactObject(JsonElement element) + { + var masked = new Dictionary(StringComparer.OrdinalIgnoreCase); + + foreach (var property in element.EnumerateObject()) + { + var propName = property.Name; + var propVal = property.Value; + + if (SensitiveKeywords.Any(k => propName.Contains(k, StringComparison.OrdinalIgnoreCase))) + { + masked[propName] = "[REDACTED]"; + continue; + } + + switch (propVal.ValueKind) + { + // Omit large arrays + case JsonValueKind.Array when propVal.GetRawText() + .Length > MaxPropertyLength: + masked[propName] = "[OMITTED_DUE_TO_SIZE]"; + break; + case JsonValueKind.String: + { + var s = propVal.GetString() ?? string.Empty; + masked[propName] = s.Length > MaxPropertyLength + ? "[OMITTED_DUE_TO_SIZE]" + : RedactSensitiveString(s); + break; + } + default: + masked[propName] = RedactSensitiveData(propVal); + break; + } + } + + return masked; + } + + private static string RedactSensitiveString(string? value) + { + if (string.IsNullOrWhiteSpace(value)) + return string.Empty; + + return SensitiveKeywords.Any(k => value.Contains(k, StringComparison.OrdinalIgnoreCase)) + ? "[REDACTED]" + : value; + } +} \ No newline at end of file diff --git a/src/SharedKernel/Logging/RequestLoggingMiddleware.cs b/src/SharedKernel/Logging/RequestLoggingMiddleware.cs new file mode 100644 index 0000000..adc354e --- /dev/null +++ b/src/SharedKernel/Logging/RequestLoggingMiddleware.cs @@ -0,0 +1,85 @@ +using System.Diagnostics; +using System.Text.Json; +using Microsoft.AspNetCore.Http; +using Microsoft.Extensions.Logging; + +namespace SharedKernel.Logging; + +internal sealed class RequestLoggingMiddleware( + RequestDelegate next, + ILogger logger) +{ + public async Task InvokeAsync(HttpContext context) + { + if (HttpMethods.IsOptions(context.Request.Method)) + { + await next(context); + return; + } + + var requestLog = await CaptureRequestAsync(context.Request); + var originalBodyStream = context.Response.Body; + + await using var responseBody = new MemoryStream(); + context.Response.Body = responseBody; + + var stopwatch = Stopwatch.GetTimestamp(); + + try + { + await next(context); + } + finally + { + var elapsedMs = Stopwatch.GetElapsedTime(stopwatch) + .TotalMilliseconds; + var responseLog = await CaptureResponseAsync(context.Response); + + logger.LogInformation( + "[Incoming Request] HTTP {Method} {Query} responded with {StatusCode} in {ElapsedMilliseconds}ms. " + + "Request Headers: {RequestHeaders}, Request Body: {RequestBody}, " + + "Response Headers: {ResponseHeaders}, Response Body: {ResponseBody}", + context.Request.Method, + context.Request.QueryString, + context.Response.StatusCode, + elapsedMs, + requestLog.Headers, + requestLog.Body, + responseLog.Headers, + responseLog.Body); + + await responseBody.CopyToAsync(originalBodyStream); + } + } + + private static async Task<(string Headers, string Body)> CaptureRequestAsync(HttpRequest request) + { + request.EnableBuffering(); + var (headers, bodyContent) = await CaptureLogAsync(request.Body, request.Headers); + request.Body.Position = 0; + return (headers, bodyContent); + } + + private static async Task<(string Headers, string Body)> CaptureResponseAsync(HttpResponse response) + { + response.Body.Seek(0, SeekOrigin.Begin); + var (headers, bodyContent) = await CaptureLogAsync(response.Body, response.Headers); + response.Body.Seek(0, SeekOrigin.Begin); + return (headers, bodyContent); + } + + private static async Task<(string Headers, string Body)> CaptureLogAsync(Stream bodyStream, + IHeaderDictionary headers) + { + using var reader = new StreamReader(bodyStream, leaveOpen: true); + var body = await reader.ReadToEndAsync(); + + var sanitizedHeaders = RedactionHelper.RedactHeaders(headers); + var redactedBody = RedactionHelper.ParseAndRedactJson(body); + + return ( + JsonSerializer.Serialize(sanitizedHeaders), + JsonSerializer.Serialize(redactedBody) + ); + } +} \ No newline at end of file diff --git a/src/SharedKernel/Logging/RequestResponseLoggingMiddleware.cs b/src/SharedKernel/Logging/RequestResponseLoggingMiddleware.cs deleted file mode 100644 index d718a6b..0000000 --- a/src/SharedKernel/Logging/RequestResponseLoggingMiddleware.cs +++ /dev/null @@ -1,178 +0,0 @@ -using System.Diagnostics; -using System.Text.Json; -using Microsoft.AspNetCore.Http; -using Microsoft.Extensions.Logging; - -namespace SharedKernel.Logging; - -internal class RequestResponseLoggingMiddleware(RequestDelegate next, ILogger logger) -{ - private static readonly HashSet SensitiveKeywords = new(StringComparer.OrdinalIgnoreCase) - { - "pwd", - "pass", - "secret", - "token", - "cookie", - "auth" - }; - - public async Task InvokeAsync(HttpContext context) - { - if (HttpMethods.IsOptions(context.Request.Method)) - { - await next(context); - return; - } - - var requestLog = await CaptureRequestAsync(context.Request); - - // Swap the response stream to capture the response - var originalBodyStream = context.Response.Body; - await using var responseBody = new MemoryStream(); - context.Response.Body = responseBody; - - var stopwatch = Stopwatch.GetTimestamp(); - try - { - await next(context); - } - finally - { - var delta = Stopwatch.GetElapsedTime(stopwatch) - .TotalMilliseconds; - var responseLog = await CaptureResponseAsync(context.Response); - - logger.LogInformation( - "Request {Method} {Query} responded {StatusCode} in {ElapsedMilliseconds}ms. RequestHeaders: {RequestHeaders}, RequestBody: {RequestBody}, ResponseHeaders: {ResponseHeaders}, ResponseBody: {ResponseBody}", - context.Request.Method, - context.Request.QueryString, - context.Response.StatusCode, - delta, - requestLog.Headers, - requestLog.Body, - responseLog.Headers, - responseLog.Body); - - // Reset the response body to the original stream - await responseBody.CopyToAsync(originalBodyStream); - } - } - - private static async Task<(string Headers, string Body)> CaptureRequestAsync(HttpRequest request) - { - request.EnableBuffering(); - var (headers, bodyContent) = await CaptureLogAsync(request.Body, request.Headers); - request.Body.Position = 0; - return (headers, bodyContent); - } - - private static async Task<(string Headers, string Body)> CaptureResponseAsync(HttpResponse response) - { - response.Body.Seek(0, SeekOrigin.Begin); - var (headers, bodyContent) = await CaptureLogAsync(response.Body, response.Headers); - response.Body.Seek(0, SeekOrigin.Begin); - return (headers, bodyContent); - } - - private static async Task<(string Headers, string Body)> CaptureLogAsync(Stream bodyStream, - IHeaderDictionary headers) - { - using var reader = new StreamReader(bodyStream, leaveOpen: true); - var body = await reader.ReadToEndAsync(); - var sanitizedHeaders = JsonSerializer.Serialize(RedactSensitiveData(headers)); - var bodyContent = JsonSerializer.Serialize(ParseAndRedactJson(body)); - return (sanitizedHeaders, bodyContent); - } - - private static object ParseAndRedactJson(string body) - { - if (string.IsNullOrWhiteSpace(body)) - { - return string.Empty; - } - - try - { - var jsonElement = JsonSerializer.Deserialize(body); - return RedactSensitiveData(jsonElement); - } - catch (JsonException) - { - // Return the body as a string if it’s not valid JSON, - // but still wrapped in an object to avoid conversion to a string - return RedactSensitiveString(body); - } - } - - private static Dictionary RedactSensitiveData(IHeaderDictionary headers) - { - var result = new Dictionary(StringComparer.OrdinalIgnoreCase); - - foreach (var header in headers) - { - var key = header.Key; - var value = SensitiveKeywords.Any(keyword => key.Contains(keyword, StringComparison.OrdinalIgnoreCase)) - ? "[REDACTED]" - : header.Value.ToString(); - - result[key] = value; - } - - return result; - } - - private static object RedactSensitiveData(JsonElement element) - { - switch (element.ValueKind) - { - case JsonValueKind.Object: - var maskedObject = new Dictionary(); - foreach (var property in element.EnumerateObject()) - { - var propertyName = property.Name; - - if (SensitiveKeywords.Any(keyword => propertyName.Contains(keyword, StringComparison.OrdinalIgnoreCase))) - { - maskedObject[propertyName] = "[REDACTED]"; - } - else - { - maskedObject[propertyName] = RedactSensitiveData(property.Value); - } - } - - return maskedObject; - - case JsonValueKind.Array: - var maskedArray = element.EnumerateArray() - .Select(RedactSensitiveData) - .ToArray(); - return maskedArray; - - case JsonValueKind.String: - var stringValue = element.GetString(); - return RedactSensitiveString(stringValue); - - case JsonValueKind.Undefined: - case JsonValueKind.Number: - case JsonValueKind.True: - case JsonValueKind.False: - case JsonValueKind.Null: - default: - return element.GetRawText(); - } - } - - private static string RedactSensitiveString(string? value) - { - if (string.IsNullOrWhiteSpace(value)) - { - return string.Empty; - } - - return SensitiveKeywords.Any(keyword => value.Contains(keyword, StringComparison.OrdinalIgnoreCase)) - ? "[REDACTED]" - : value; - } -} \ No newline at end of file diff --git a/src/SharedKernel/SharedKernel.csproj b/src/SharedKernel/SharedKernel.csproj index 88b2b52..8deb8e8 100644 --- a/src/SharedKernel/SharedKernel.csproj +++ b/src/SharedKernel/SharedKernel.csproj @@ -8,13 +8,13 @@ Readme.md Pandatech MIT - 1.0.25 + 1.1.0 Pandatech.SharedKernel Pandatech Shared Kernel Library Pandatech, shared kernel, library, OpenAPI, Swagger, utilities, scalar Pandatech.SharedKernel provides centralized configurations, utilities, and extensions for ASP.NET Core projects. For more information refere to readme.md document. https://github.com/PandaTechAM/be-lib-sharedkernel - Nuget updates + app.UseRequestResponseLogging() changed to app.UseRequestLogging() and added new HttpClientHandler loger. @@ -34,14 +34,14 @@ - - - - - - + + + + + + - + @@ -52,7 +52,7 @@ - + diff --git a/test/SharedKernel.Tests/SharedKernel.Tests.csproj b/test/SharedKernel.Tests/SharedKernel.Tests.csproj index a510ed9..32117fb 100644 --- a/test/SharedKernel.Tests/SharedKernel.Tests.csproj +++ b/test/SharedKernel.Tests/SharedKernel.Tests.csproj @@ -11,12 +11,12 @@ - - + + runtime; build; native; contentfiles; analyzers; buildtransitive all - + runtime; build; native; contentfiles; analyzers; buildtransitive all