diff --git a/SharedKernel.Demo/LoggingTestEndpoints.cs b/SharedKernel.Demo/LoggingTestEndpoints.cs new file mode 100644 index 0000000..1811397 --- /dev/null +++ b/SharedKernel.Demo/LoggingTestEndpoints.cs @@ -0,0 +1,172 @@ +using System.Text; +using FluentMinimalApiMapper; +using Microsoft.AspNetCore.Mvc; + +namespace SharedKernel.Demo; + +public class LoggingTestEndpoints : IEndpoint +{ + public void AddRoutes(IEndpointRouteBuilder app) + { + var grp = app.MapGroup("/tests") + .WithTags("logs"); + + grp.MapPost("/json", ([FromBody] TestTypes payload) => Results.Ok(payload)); + + grp.MapPost("/json-array", + ([FromBody] int[] numbers) => Results.Ok(new + { + count = numbers?.Length ?? 0, + numbers + })); + + grp.MapPost("/form-urlencoded", ([FromForm] FormUrlDto form) => Results.Ok(form)) + .DisableAntiforgery(); + + grp.MapGet("/json-per-property", + () => + { + var big = new string('x', 6_000); // ~6KB + var payload = new + { + small = "ok", + bigString = big, // should be redacted/omitted per-property + tail = "done" + }; + return Results.Json(payload); + }); + + + grp.MapPost("/multipart", + async ([FromForm] MultipartDto form) => + { + var meta = new + { + form.Description, + File = form.File is null + ? null + : new + { + form.File.FileName, + form.File.ContentType, + form.File.Length + } + }; + return Results.Ok(meta); + }) + .DisableAntiforgery(); + + grp.MapGet("/query", ([AsParameters] QueryDto q) => Results.Ok(q)); + + grp.MapGet("/route/{id:int}", + (int id) => Results.Ok(new + { + id + })); + + grp.MapPost("/headers", + ([FromHeader(Name = "x-trace-id")] string? traceId, HttpRequest req) => + { + var hasAuth = req.Headers.ContainsKey("Authorization"); + return Results.Ok(new + { + traceId, + hasAuth + }); + }); + + grp.MapGet("/binary", + () => + { + var bytes = Encoding.UTF8.GetBytes("Hello Binary"); + return Results.File(bytes, "application/octet-stream", "demo.bin"); + }); + + grp.MapGet("/no-content-type", + async (HttpContext ctx) => + { + await ctx.Response.Body.WriteAsync(Encoding.UTF8.GetBytes("raw body with no content-type")); + }); + + grp.MapGet("/large-json", + () => + { + var items = Enumerable.Range(1, 10_000) + .Select(i => new + { + i, + text = "xxxxxxxxxx" + }); + return Results.Ok(items); + }); + + grp.MapGet("/large-text", + () => + { + var sb = new StringBuilder(); + for (var i = 0; i < 20_000; i++) sb.Append('x'); + return Results.Text(sb.ToString(), "text/plain", Encoding.UTF8); + }); + + grp.MapPost("/echo-with-headers", + ([FromBody] SharedKernel.Demo.TestTypes payload, HttpResponse res) => + { + res.Headers["Custom-Header-Response"] = "CustomValue"; + res.ContentType = "application/json; charset=utf-8"; + return Results.Json(payload); + }); + + grp.MapGet("/ping", () => Results.Text("pong", "text/plain")); + + + grp.MapGet("/invalid-json", + async (HttpContext ctx) => + { + ctx.Response.StatusCode = StatusCodes.Status200OK; + ctx.Response.ContentType = "application/json"; + await ctx.Response.Body.WriteAsync("{ invalid-json: true"u8.ToArray()); + }); + + // Your HttpClient test moved here, targets our echo endpoint + grp.MapGet("/httpclient", + async (IHttpClientFactory httpClientFactory) => + { + var httpClient = httpClientFactory.CreateClient("RandomApiClient"); + httpClient.DefaultRequestHeaders.Add("auth", "hardcoded-auth-value"); + + var body = new SharedKernel.Demo.TestTypes + { + AnimalType = AnimalType.Cat, + JustText = "Hello from Get Data", + JustNumber = 100 + }; + + var content = new StringContent(System.Text.Json.JsonSerializer.Serialize(body), + System.Text.Encoding.UTF8, + "application/json"); + + var response = await httpClient.PostAsync("tests/echo-with-headers?barev=5", content); + + if (!response.IsSuccessStatusCode) + throw new Exception("Something went wrong"); + + var responseBody = await response.Content.ReadAsStringAsync(); + var testTypes = System.Text.Json.JsonSerializer.Deserialize(responseBody); + + if (testTypes == null) + throw new Exception("Failed to get data from external API"); + + return TypedResults.Ok(testTypes); + }); + } +} + +public record FormUrlDto(string? Username, string? Password, string? Note); + +public class MultipartDto +{ + public IFormFile? File { get; init; } + public string? Description { get; init; } +} + +public record QueryDto(int Page = 1, int PageSize = 10, string? Search = null, string[]? Tags = null); \ No newline at end of file diff --git a/SharedKernel.Demo/Program.cs b/SharedKernel.Demo/Program.cs index 4c8b38e..da0339c 100644 --- a/SharedKernel.Demo/Program.cs +++ b/SharedKernel.Demo/Program.cs @@ -89,13 +89,6 @@ }); }); -app.MapPost("user", - async ([FromBody] UserCommand user, ISender sender) => - { - await sender.Send(user); - return Results.Ok(); - }); - app.MapPost("/receive-file", ([FromForm] IFormFile file) => TypedResults.Ok()) .DisableAntiforgery(); @@ -110,41 +103,6 @@ return TypedResults.Ok(testTypes); }); -app.MapGet("/get-data", - async (IHttpClientFactory httpClientFactory) => - { - var httpClient = httpClientFactory.CreateClient("RandomApiClient"); - httpClient.DefaultRequestHeaders.Add("auth", "hardcoded-auth-value"); - - var body = new TestTypes - { - AnimalType = AnimalType.Cat, - JustText = "Hello from Get Data", - JustNumber = 100 - }; - var content = new StringContent(System.Text.Json.JsonSerializer.Serialize(body), - System.Text.Encoding.UTF8, - "application/json"); - - var response = await httpClient.PostAsync("body?barev=5", content); - - if (!response.IsSuccessStatusCode) - { - throw new Exception("Something went wrong"); - } - - var responseBody = await response.Content.ReadAsStringAsync(); - - var testTypes = System.Text.Json.JsonSerializer.Deserialize(responseBody); - - if (testTypes == null) - { - throw new Exception("Failed to get data from external API"); - } - - return TypedResults.Ok(testTypes); - }); - app.MapHub("/hub"); app.LogStartSuccess(); @@ -165,38 +123,4 @@ public enum AnimalType Cat, Fish } - - public record UserCommand(string Name, string Email) : ICommand; - - public class UserCommandHandler : ICommandHandler - { - public Task Handle(UserCommand request, CancellationToken cancellationToken) - { - return Task.FromResult($"User {request.Name} with email {request.Email} created successfully."); - } - } - - public class User - { - public string Name { get; set; } = string.Empty; - public string Email { get; set; } = string.Empty; - } - - public class UserValidator : AbstractValidator - { - public UserValidator() - { - RuleFor(x => x.Name) - .NotEmpty() - .WithMessage("Name is required.") - .MaximumLength(100) - .WithMessage("Name cannot exceed 100 characters."); - - RuleFor(x => x.Email) - .NotEmpty() - .WithMessage("Email is required.") - .EmailAddress() - .WithMessage("Invalid email format."); - } - } } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/CappedResponseBodyStream.cs b/src/SharedKernel/Logging/Middleware/CappedResponseBodyStream.cs new file mode 100644 index 0000000..493ccc4 --- /dev/null +++ b/src/SharedKernel/Logging/Middleware/CappedResponseBodyStream.cs @@ -0,0 +1,134 @@ +using System.Buffers; + +namespace SharedKernel.Logging.Middleware; + +internal sealed class CappedResponseBodyStream : Stream +{ + private readonly Stream _inner; + private readonly int _capBytes; + private readonly byte[] _buf; + private int _bufLen; + private long _totalWritten; + + public CappedResponseBodyStream(Stream inner, int capBytes) + { + _inner = inner; + _capBytes = capBytes; + _buf = ArrayPool.Shared.Rent(_capBytes); + _bufLen = 0; + _totalWritten = 0; + } + + public long TotalWritten + { + get { return _totalWritten; } + } + + public ReadOnlyMemory Captured + { + get { return new ReadOnlyMemory(_buf, 0, _bufLen); } + } + + private void Capture(ReadOnlySpan src) + { + if (_bufLen >= _capBytes) + { + return; + } + + var toCopy = Math.Min(_capBytes - _bufLen, src.Length); + if (toCopy <= 0) + { + return; + } + + src[..toCopy] + .CopyTo(_buf.AsSpan(_bufLen)); + _bufLen += toCopy; + } + + public override void Write(byte[] buffer, int offset, int count) + { + _inner.Write(buffer, offset, count); + _totalWritten += count; + Capture(new ReadOnlySpan(buffer, offset, count)); + } + + public override async Task WriteAsync(byte[] buffer, int offset, int count, CancellationToken cancellationToken) + { + await _inner.WriteAsync(buffer.AsMemory(offset, count), cancellationToken); + _totalWritten += count; + Capture(new ReadOnlySpan(buffer, offset, count)); + } + + public override ValueTask WriteAsync(ReadOnlyMemory buffer, CancellationToken cancellationToken = default) + { + var vt = _inner.WriteAsync(buffer, cancellationToken); + _totalWritten += buffer.Length; + Capture(buffer.Span); + return vt; + } + + public override void Flush() + { + _inner.Flush(); + } + + public override Task FlushAsync(CancellationToken cancellationToken) + { + return _inner.FlushAsync(cancellationToken); + } + + protected override void Dispose(bool disposing) + { + try + { + base.Dispose(disposing); + } + finally + { + ArrayPool.Shared.Return(_buf); + } + } + + public override bool CanRead + { + get { return false; } + } + + public override bool CanSeek + { + get { return false; } + } + + public override bool CanWrite + { + get { return true; } + } + + public override long Length + { + get { throw new NotSupportedException(); } + } + + public override long Position + { + get { throw new NotSupportedException(); } + set { throw new NotSupportedException(); } + } + + public override int Read(byte[] buffer, int offset, int count) + { + throw new NotSupportedException(); + } + + public override long Seek(long offset, SeekOrigin origin) + { + throw new NotSupportedException(); + } + + public override void SetLength(long value) + { + throw new NotSupportedException(); + } +} \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/HttpLogHelper.cs b/src/SharedKernel/Logging/Middleware/HttpLogHelper.cs index bf9a5c7..deba294 100644 --- a/src/SharedKernel/Logging/Middleware/HttpLogHelper.cs +++ b/src/SharedKernel/Logging/Middleware/HttpLogHelper.cs @@ -1,71 +1,94 @@ using System.Text; using Microsoft.AspNetCore.Http; +using Microsoft.Net.Http.Headers; namespace SharedKernel.Logging.Middleware; internal static class HttpLogHelper { - // defaults; can be overridden via Configure(options) - - public static async Task<(string Headers, string Body)> CaptureAsync(Stream bodyStream, + public static async Task<(object Headers, object Body)> CaptureAsync(Stream bodyStream, IHeaderDictionary headers, - string? mediaType) + string? contentType) { - var hdrs = RedactionHelper.RedactHeaders(headers); + var redactedHeaders = RedactionHelper.RedactHeaders(headers); + + var textLike = MediaTypeUtil.IsTextLike(contentType); + var hasContentLength = headers.ContainsKey(HeaderNames.ContentLength); + var len = GetContentLengthOrNull(headers); + var hasChunked = headers.TryGetValue(HeaderNames.TransferEncoding, out _); - if (!IsTextLike(mediaType)) + if ((hasContentLength && len == 0) || + (!hasContentLength && !hasChunked && string.IsNullOrWhiteSpace(contentType))) { - long? len = null; - if (headers.TryGetValue("Content-Length", out var clVal) && - long.TryParse(clVal.ToString(), out var cl)) - len = cl; - - return (LogFormatting.Json(hdrs), - LogFormatting.Json(BuildOmittedBodyMessage("non-text", - len, - mediaType, - LoggingOptions.RequestResponseBodyMaxBytes))); + return (redactedHeaders, new Dictionary()); } - var (raw, truncated) = await ReadLimitedAsync(bodyStream, LoggingOptions.RequestResponseBodyMaxBytes); + if (!textLike) + { + return (redactedHeaders, LogFormatting.Omitted( + reason: "non-text", + lengthBytes: len, + mediaType: MediaTypeUtil.Normalize(contentType), + thresholdBytes: LoggingOptions.RequestResponseBodyMaxBytes)); + } + var (raw, truncated) = await ReadLimitedAsync(bodyStream, LoggingOptions.RequestResponseBodyMaxBytes); if (truncated) - return (LogFormatting.Json(hdrs), - LogFormatting.Json($"[OMITTED: body exceeds {LoggingOptions.RequestResponseBodyMaxBytes / 1024}KB]")); + { + return (redactedHeaders, LogFormatting.Omitted( + reason: "exceeds-limit", + lengthBytes: LoggingOptions.RequestResponseBodyMaxBytes, + mediaType: MediaTypeUtil.Normalize(contentType), + thresholdBytes: LoggingOptions.RequestResponseBodyMaxBytes)); + } - var body = RedactionHelper.RedactBody(mediaType, raw); - return (LogFormatting.Json(hdrs), LogFormatting.Json(body)); + var body = RedactionHelper.RedactBody(contentType, raw); + return (redactedHeaders, body); } - public static async Task<(string Headers, string Body)> CaptureAsync(Dictionary> headers, + public static async Task<(object Headers, object Body)> CaptureAsync(Dictionary> headers, Func> rawReader, - string? mediaType) + string? contentType) { - var hdrs = RedactionHelper.RedactHeaders(headers); + var redactedHeaders = RedactionHelper.RedactHeaders(headers); - if (!IsTextLike(mediaType)) - return (LogFormatting.Json(hdrs), LogFormatting.Json(string.Empty)); + if (!MediaTypeUtil.IsTextLike(contentType)) + { + return (redactedHeaders, new Dictionary()); + } var raw = await rawReader(); + if (Utf8ByteCount(raw) > LoggingOptions.RequestResponseBodyMaxBytes) { - return (LogFormatting.Json(hdrs), - LogFormatting.Json($"[OMITTED: body exceeds {LoggingOptions.RequestResponseBodyMaxBytes / 1024}KB]")); + return (redactedHeaders, LogFormatting.Omitted( + reason: "exceeds-limit", + lengthBytes: Utf8ByteCount(raw), + mediaType: MediaTypeUtil.Normalize(contentType), + thresholdBytes: LoggingOptions.RequestResponseBodyMaxBytes)); } - var body = RedactionHelper.RedactBody(mediaType, raw); - return (LogFormatting.Json(hdrs), LogFormatting.Json(body)); + var body = RedactionHelper.RedactBody(contentType, raw); + return (redactedHeaders, body); } public static Dictionary> CreateHeadersDictionary(HttpRequestMessage req) { var dict = new Dictionary>(StringComparer.OrdinalIgnoreCase); - foreach (var h in req.Headers) dict[h.Key] = h.Value; + foreach (var h in req.Headers) + { + dict[h.Key] = h.Value; + } var contentHeaders = req.Content?.Headers; + if (contentHeaders != null) + { foreach (var h in contentHeaders) + { dict[h.Key] = h.Value; + } + } return dict; } @@ -74,21 +97,30 @@ public static Dictionary> CreateHeadersDictionary(Ht { var dict = new Dictionary>(StringComparer.OrdinalIgnoreCase); foreach (var h in res.Headers) dict[h.Key] = h.Value; - foreach (var h in res.Content.Headers) dict[h.Key] = h.Value; + + var ch = res.Content?.Headers; + if (ch != null) + { + foreach (var h in ch) + { + dict[h.Key] = h.Value; + } + } + return dict; } - internal static string BuildOmittedBodyMessage(string reason, - long? lengthBytes, - string? mediaType, - int thresholdBytes) => - LogFormatting.Omitted(reason, lengthBytes, mediaType, thresholdBytes); + internal static bool IsTextLike(string? mediaType) => MediaTypeUtil.IsTextLike(mediaType); - internal static bool IsTextLike(string? mediaType) + private static long? GetContentLengthOrNull(IHeaderDictionary headers) { - if (string.IsNullOrWhiteSpace(mediaType)) return false; - return LoggingOptions.TextLikeMediaPrefixes.Any(m => mediaType.StartsWith(m, StringComparison.OrdinalIgnoreCase)) - || mediaType.EndsWith("+json", StringComparison.OrdinalIgnoreCase); + if (headers.TryGetValue("Content-Length", out var clVal) && + long.TryParse(clVal.ToString(), out var cl)) + { + return cl; + } + + return null; } private static async Task<(string text, bool truncated)> ReadLimitedAsync(Stream s, int maxBytes) diff --git a/src/SharedKernel/Logging/Middleware/LogFormatting.cs b/src/SharedKernel/Logging/Middleware/LogFormatting.cs index af106c4..984cdec 100644 --- a/src/SharedKernel/Logging/Middleware/LogFormatting.cs +++ b/src/SharedKernel/Logging/Middleware/LogFormatting.cs @@ -1,16 +1,17 @@ -using System.Text.Json; - -namespace SharedKernel.Logging.Middleware; +namespace SharedKernel.Logging.Middleware; internal static class LogFormatting { - public static string Json(object? o) => JsonSerializer.Serialize(o); - - public static string Omitted(string reason, long? lenBytes, string? mediaType, int thresholdBytes) + public static object Omitted(string reason, long? lengthBytes, string? mediaType, int thresholdBytes) { - var thresholdKb = thresholdBytes / 1024; - var len = lenBytes.HasValue ? $"{lenBytes.Value}B (~{lenBytes.Value / 1024}KB)" : "unknown"; - var ct = string.IsNullOrWhiteSpace(mediaType) ? "unknown" : mediaType; - return $"[OMITTED] reason={reason}; length={len}; threshold={thresholdKb}KB; contentType={ct}"; + int? sizeKb = lengthBytes.HasValue ? (int)Math.Round(lengthBytes.Value / 1024d) : null; + return new Dictionary + { + ["omitted"] = true, + ["reason"] = reason, + ["sizeKb"] = sizeKb, + ["thresholdKb"] = thresholdBytes / 1024, + ["contentType"] = MediaTypeUtil.Normalize(mediaType) + }; } } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/LoggingOptions.cs b/src/SharedKernel/Logging/Middleware/LoggingOptions.cs index 2c9c826..568d052 100644 --- a/src/SharedKernel/Logging/Middleware/LoggingOptions.cs +++ b/src/SharedKernel/Logging/Middleware/LoggingOptions.cs @@ -28,7 +28,7 @@ public static class LoggingOptions "bankaccount", "notboundcard" }; - + // was HttpLogHelper.TextLikeMedia public static readonly string[] TextLikeMediaPrefixes = @@ -42,6 +42,8 @@ public static class LoggingOptions public static readonly HashSet PathsToIgnore = new(StringComparer.OrdinalIgnoreCase) { "/openapi", - "/above-board" + "/above-board", + "/favicon.ico", + "/swagger" }; } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/MediaTypeUtil.cs b/src/SharedKernel/Logging/Middleware/MediaTypeUtil.cs new file mode 100644 index 0000000..5d7a1a9 --- /dev/null +++ b/src/SharedKernel/Logging/Middleware/MediaTypeUtil.cs @@ -0,0 +1,45 @@ +using Microsoft.Net.Http.Headers; + +namespace SharedKernel.Logging.Middleware; + +internal static class MediaTypeUtil +{ + public static string? Normalize(string? contentType) + { + if (string.IsNullOrWhiteSpace(contentType)) + { + return null; + } + + try + { + var mt = MediaTypeHeaderValue.Parse(contentType); + return mt.MediaType.Value; // e.g. "application/json" + } + catch + { + var semi = contentType.IndexOf(';'); + return (semi >= 0 ? contentType[..semi] : contentType).Trim(); + } + } + + public static bool IsJson(string? contentType) + { + var mt = Normalize(contentType); + return !string.IsNullOrWhiteSpace(mt) && + (mt.EndsWith("/json", StringComparison.OrdinalIgnoreCase) || + mt.EndsWith("+json", StringComparison.OrdinalIgnoreCase)); + } + + public static bool IsTextLike(string? contentType) + { + var mt = Normalize(contentType); + if (string.IsNullOrWhiteSpace(mt)) + { + return false; + } + + return LoggingOptions.TextLikeMediaPrefixes.Any(p => mt.StartsWith(p, StringComparison.OrdinalIgnoreCase)) || + mt.EndsWith("+json", StringComparison.OrdinalIgnoreCase); + } +} \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/OutboundLoggingHandler.cs b/src/SharedKernel/Logging/Middleware/OutboundLoggingHandler.cs index 5278757..342a616 100644 --- a/src/SharedKernel/Logging/Middleware/OutboundLoggingHandler.cs +++ b/src/SharedKernel/Logging/Middleware/OutboundLoggingHandler.cs @@ -1,5 +1,5 @@ using System.Diagnostics; -using System.Text.Json; +using Microsoft.AspNetCore.WebUtilities; using Microsoft.Extensions.Logging; namespace SharedKernel.Logging.Middleware; @@ -15,22 +15,118 @@ protected override async Task SendAsync(HttpRequestMessage var reqMedia = request.Content?.Headers.ContentType?.MediaType; var reqLen = request.Content?.Headers.ContentLength; - string reqHeaders, reqBody; - if (!HttpLogHelper.IsTextLike(reqMedia) || reqLen is > LoggingOptions.RequestResponseBodyMaxBytes) - { - reqHeaders = JsonSerializer.Serialize(RedactionHelper.RedactHeaders(reqHdrDict)); + object reqHeaders; + object reqBody; + + var isFormLike = + string.Equals(reqMedia, "application/x-www-form-urlencoded", StringComparison.OrdinalIgnoreCase) || + string.Equals(reqMedia, "multipart/form-data", StringComparison.OrdinalIgnoreCase); - var reason = !HttpLogHelper.IsTextLike(reqMedia) - ? "non-text" - : reqLen.HasValue - ? "exceeds-limit" - : "unknown-length"; + if (request.Content is null) + { + reqHeaders = RedactionHelper.RedactHeaders(reqHdrDict); + reqBody = new Dictionary(); + } + else if (isFormLike) + { + reqHeaders = RedactionHelper.RedactHeaders(reqHdrDict); - reqBody = JsonSerializer.Serialize( - HttpLogHelper.BuildOmittedBodyMessage(reason, + if (reqLen is null or > LoggingOptions.RequestResponseBodyMaxBytes) + { + reqBody = LogFormatting.Omitted("form-large-or-unknown", reqLen, reqMedia, - LoggingOptions.RequestResponseBodyMaxBytes)); + LoggingOptions.RequestResponseBodyMaxBytes); + } + else + { + var fields = new Dictionary(StringComparer.OrdinalIgnoreCase); + + switch (request.Content) + { + case FormUrlEncodedContent: + { + var raw = await request.Content.ReadAsStringAsync(cancellationToken); + var parsed = QueryHelpers.ParseQuery("?" + raw); + foreach (var kvp in parsed) + { + var k = kvp.Key; + if (string.IsNullOrEmpty(k)) + { + continue; + } + + fields[k] = RedactionHelper.RedactFormValue(k, string.Join(";", kvp.Value.ToArray())); + } + + break; + } + case MultipartFormDataContent mfd: + { + var fileCounts = new Dictionary(StringComparer.OrdinalIgnoreCase); + var fileSizes = new Dictionary(StringComparer.OrdinalIgnoreCase); + + foreach (var part in mfd) + { + var cd = part.Headers.ContentDisposition; + var name = cd?.Name?.Trim('"') ?? "field"; + var isFile = cd != null && + (!string.IsNullOrEmpty(cd.FileName) || !string.IsNullOrEmpty(cd.FileNameStar)); + + if (isFile) + { + fileCounts.TryGetValue(name, out var c); + fileCounts[name] = c + 1; + + if (part.Headers.ContentLength.HasValue) + { + fileSizes.TryGetValue(name, out var b); + fileSizes[name] = b + part.Headers.ContentLength.Value; + } + + continue; + } + + var value = await part.ReadAsStringAsync(cancellationToken); + fields[name] = RedactionHelper.RedactFormValue(name, value); + } + + foreach (var name in fileCounts.Keys) + { + var count = fileCounts[name]; + fileSizes.TryGetValue(name, out var bytes); + var hasSize = bytes > 0; + var sizeKb = hasSize ? (int)Math.Round(bytes / 1024d) : (int?)null; + + var place = count == 1 + ? hasSize ? $"[OMITTED: file {sizeKb}KB]" : "[OMITTED: file]" + : hasSize + ? $"[OMITTED: {count} files {sizeKb}KB]" + : $"[OMITTED: {count} files]"; + + if (fields.TryGetValue(name, out var existing) && !string.IsNullOrWhiteSpace(existing)) + { + fields[name] = $"{existing}; {place}"; + } + else + { + fields[name] = place; + } + } + + break; + } + } + + reqBody = fields; + } + } + else if (!HttpLogHelper.IsTextLike(reqMedia) || !reqLen.HasValue || + reqLen.Value > LoggingOptions.RequestResponseBodyMaxBytes) + { + reqHeaders = RedactionHelper.RedactHeaders(reqHdrDict); + var reason = !HttpLogHelper.IsTextLike(reqMedia) ? "non-text" : "exceeds-limit-or-unknown"; + reqBody = LogFormatting.Omitted(reason, reqLen, reqMedia, LoggingOptions.RequestResponseBodyMaxBytes); } else { @@ -50,22 +146,23 @@ protected override async Task SendAsync(HttpRequestMessage var resMedia = response.Content.Headers.ContentType?.MediaType; var resLen = response.Content.Headers.ContentLength; - string resHeaders, resBody; - if (!HttpLogHelper.IsTextLike(resMedia) || resLen is > LoggingOptions.RequestResponseBodyMaxBytes) + object resHeaders; + object resBody; + + if (!HttpLogHelper.IsTextLike(resMedia) || !resLen.HasValue || + resLen.Value > LoggingOptions.RequestResponseBodyMaxBytes) { - resHeaders = JsonSerializer.Serialize(RedactionHelper.RedactHeaders(resHdrDict)); - - var reason = !HttpLogHelper.IsTextLike(resMedia) - ? "non-text" - : resLen.HasValue - ? "exceeds-limit" - : "unknown-length"; - - resBody = JsonSerializer.Serialize( - HttpLogHelper.BuildOmittedBodyMessage(reason, - resLen, - resMedia, - LoggingOptions.RequestResponseBodyMaxBytes)); + resHeaders = RedactionHelper.RedactHeaders(resHdrDict); + + if (resLen == 0) + { + resBody = new Dictionary(); + } + else + { + var reason = !HttpLogHelper.IsTextLike(resMedia) ? "non-text" : "exceeds-limit-or-unknown"; + resBody = LogFormatting.Omitted(reason, resLen, resMedia, LoggingOptions.RequestResponseBodyMaxBytes); + } } else { @@ -75,9 +172,7 @@ protected override async Task SendAsync(HttpRequestMessage resMedia); } - var hostPath = request.RequestUri is null - ? "" - : request.RequestUri.GetLeftPart(UriPartial.Path); // message: path only (no query) + var hostPath = request.RequestUri is null ? "" : request.RequestUri.GetLeftPart(UriPartial.Path); var scope = new Dictionary { @@ -89,10 +184,9 @@ protected override async Task SendAsync(HttpRequestMessage ["Kind"] = "HttpOut" }; - var query = request.RequestUri?.Query; - if (!string.IsNullOrEmpty(query)) + if (!string.IsNullOrEmpty(request.RequestUri?.Query)) { - scope["Query"] = query; + scope["Query"] = request.RequestUri!.Query; } using (logger.BeginScope(scope)) @@ -102,10 +196,9 @@ protected override async Task SendAsync(HttpRequestMessage request.Method, hostPath, (int)response.StatusCode, - elapsed - ); - - return response; + elapsed); } + + return response; } } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/ReductionHelper.cs b/src/SharedKernel/Logging/Middleware/ReductionHelper.cs index 5632cda..94ecd57 100644 --- a/src/SharedKernel/Logging/Middleware/ReductionHelper.cs +++ b/src/SharedKernel/Logging/Middleware/ReductionHelper.cs @@ -1,11 +1,15 @@ -using System.Text; +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 { + // ------- Headers ------- + public static Dictionary RedactHeaders(IHeaderDictionary headers) => headers.ToDictionary( h => h.Key, @@ -20,11 +24,17 @@ public static Dictionary RedactHeaders(Dictionary(); + } - if (IsJsonMediaType(mediaType)) + // JSON (including +json) + if (MediaTypeUtil.IsJson(contentType)) { try { @@ -33,45 +43,108 @@ public static object RedactBody(string? mediaType, string raw) } catch (JsonException) { - return "[INVALID_JSON]"; + return new Dictionary { ["invalidJson"] = true }; } } - if (mediaType?.Equals("application/x-www-form-urlencoded", StringComparison.OrdinalIgnoreCase) == true) + // application/x-www-form-urlencoded + if (string.Equals(MediaTypeUtil.Normalize(contentType), + "application/x-www-form-urlencoded", + StringComparison.OrdinalIgnoreCase)) { - var nvc = System.Web.HttpUtility.ParseQueryString(raw); - var keys = nvc.AllKeys; - var dict = new Dictionary(StringComparer.OrdinalIgnoreCase); - foreach (var k in keys) + var parsed = QueryHelpers.ParseQuery("?" + raw); + foreach (var kvp in parsed) { - if (string.IsNullOrEmpty(k)) continue; - var v = nvc[k] ?? string.Empty; - dict[k] = LoggingOptions.SensitiveKeywords.Any(s => - k.Contains(s, StringComparison.OrdinalIgnoreCase) || - v.Contains(s, StringComparison.OrdinalIgnoreCase)) - ? "[REDACTED]" - : v; + var k = kvp.Key; + + if (string.IsNullOrEmpty(k)) + { + continue; + } + + var joined = string.Join(";", kvp.Value.ToArray()); + dict[k] = RedactFormValue(k, joined); } return dict; } var rawBytes = Encoding.UTF8.GetByteCount(raw); - if (rawBytes <= LoggingOptions.RedactionMaxPropertyBytes) + + if (rawBytes > LoggingOptions.RedactionMaxPropertyBytes) { - return LoggingOptions.SensitiveKeywords.Any(s => raw.Contains(s, StringComparison.OrdinalIgnoreCase)) - ? "[REDACTED]" - : raw; + return new Dictionary + { + ["text"] = $"[OMITTED: exceeds-limit ~{rawBytes / 1024}KB]" + }; + } + + var val = LoggingOptions.SensitiveKeywords.Any(s => raw.Contains(s, StringComparison.OrdinalIgnoreCase)) + ? "[REDACTED]" + : raw; + + return new Dictionary + { + ["text"] = val + }; + } + + // ------- Forms (fields only; add file placeholders) ------- + + 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 + if (form.Files.Count <= 0) + { + return fields; + } + + var counts = new Dictionary(StringComparer.OrdinalIgnoreCase); + var sizes = new Dictionary(StringComparer.OrdinalIgnoreCase); + + foreach (var f in form.Files) + { + var key = f.Name; + counts.TryGetValue(key, out var c); + counts[key] = c + 1; + + sizes.TryGetValue(key, out var b); + sizes[key] = b + f.Length; } - return HttpLogHelper.BuildOmittedBodyMessage("exceeds-limit", rawBytes, mediaType, LoggingOptions.RedactionMaxPropertyBytes); + foreach (var key in counts.Keys) + { + var count = counts[key]; + var sizeKb = (int)Math.Round(sizes[key] / 1024d); + + var place = count == 1 + ? $"[OMITTED: file {sizeKb}KB]" + : $"[OMITTED: {count} files {sizeKb}KB]"; + + if (fields.TryGetValue(key, out var existing) && !string.IsNullOrWhiteSpace(existing)) + { + fields[key] = $"{existing}; {place}"; + } + else + { + fields[key] = place; + } + } + + return fields; } - private static bool IsJsonMediaType(string? mediaType) => - !string.IsNullOrWhiteSpace(mediaType) - && (mediaType.EndsWith("/json", StringComparison.OrdinalIgnoreCase) - || mediaType.EndsWith("+json", StringComparison.OrdinalIgnoreCase)); + // ------- Helpers ------- private static object RedactElement(JsonElement el) => el.ValueKind switch @@ -87,6 +160,13 @@ private static object RedactElement(JsonElement el) => .Select(RedactElement) .ToArray(), JsonValueKind.String => RedactString(el.GetString()!), + JsonValueKind.Number => el.TryGetInt64(out var i) ? i : + el.TryGetDouble(out var d) ? d : + decimal.TryParse(el.GetRawText(), NumberStyles.Any, CultureInfo.InvariantCulture, out var m) ? m : + el.GetRawText(), + JsonValueKind.True => true, + JsonValueKind.False => false, + JsonValueKind.Null => null!, _ => el.GetRawText() }; @@ -100,6 +180,20 @@ private static string RedactString(string value) : value; } - return HttpLogHelper.BuildOmittedBodyMessage("exceeds-limit", bytes, null, LoggingOptions.RedactionMaxPropertyBytes); + return $"[OMITTED: exceeds-limit ~{bytes / 1024}KB]"; + } + + internal static string RedactFormValue(string key, string value) + { + if (LoggingOptions.SensitiveKeywords.Any(k => + key.Contains(k, StringComparison.OrdinalIgnoreCase) || + value.Contains(k, StringComparison.OrdinalIgnoreCase))) + { + return "[REDACTED]"; + } + + var bytes = Encoding.UTF8.GetByteCount(value); + + return bytes > LoggingOptions.RedactionMaxPropertyBytes ? $"[OMITTED: exceeds-limit ~{bytes / 1024}KB]" : value; } } \ No newline at end of file diff --git a/src/SharedKernel/Logging/Middleware/RequestLoggingMiddleware.cs b/src/SharedKernel/Logging/Middleware/RequestLoggingMiddleware.cs index d4c7c38..5361879 100644 --- a/src/SharedKernel/Logging/Middleware/RequestLoggingMiddleware.cs +++ b/src/SharedKernel/Logging/Middleware/RequestLoggingMiddleware.cs @@ -1,18 +1,13 @@ using System.Diagnostics; -using System.Text.Json; using Microsoft.AspNetCore.Http; -using Microsoft.AspNetCore.Http.Extensions; using Microsoft.Extensions.Logging; namespace SharedKernel.Logging.Middleware; -internal sealed class RequestLoggingMiddleware( - RequestDelegate next, - ILogger logger) +internal sealed class RequestLoggingMiddleware(RequestDelegate next, ILogger logger) { public async Task InvokeAsync(HttpContext context) { - // preserve original behavior: ignore OPTIONS and listed prefixes if (HttpMethods.IsOptions(context.Request.Method) || (context.Request.Path.HasValue && LoggingOptions.PathsToIgnore.Any(p => context.Request.Path.StartsWithSegments(p)))) @@ -21,19 +16,58 @@ public async Task InvokeAsync(HttpContext context) return; } - // enable request buffering and capture - context.Request.EnableBuffering(); - var (reqHeaders, reqBody) = await HttpLogHelper.CaptureAsync( - context.Request.Body, - context.Request.Headers, - context.Request.ContentType); + var normReqCt = MediaTypeUtil.Normalize(context.Request.ContentType); + var reqLen = context.Request.ContentLength; + var isFormLike = + string.Equals(normReqCt, "application/x-www-form-urlencoded", StringComparison.OrdinalIgnoreCase) || + string.Equals(normReqCt, "multipart/form-data", StringComparison.OrdinalIgnoreCase); - await using var responseBuffer = - new Microsoft.AspNetCore.WebUtilities.FileBufferingWriteStream( - bufferLimit: LoggingOptions.ResponseBufferLimitBytes); + var looksEmpty = + reqLen == 0 || + (!reqLen.HasValue && string.IsNullOrWhiteSpace(normReqCt) && + !context.Request.Headers.ContainsKey("Transfer-Encoding")); + + object reqHeaders = RedactionHelper.RedactHeaders(context.Request.Headers); + object reqBody; + + if (looksEmpty) + { + reqBody = new Dictionary(); + } + else if (isFormLike) + { + if (reqLen is null or > LoggingOptions.RequestResponseBodyMaxBytes) + { + reqBody = LogFormatting.Omitted("form-large-or-unknown", + reqLen, + normReqCt, + LoggingOptions.RequestResponseBodyMaxBytes); + } + else + { + var form = await context.Request.ReadFormAsync(context.RequestAborted); + reqBody = RedactionHelper.RedactFormFields(form); + } + } + else if (MediaTypeUtil.IsTextLike(normReqCt) && reqLen is <= LoggingOptions.RequestResponseBodyMaxBytes) + { + context.Request.EnableBuffering(); + (reqHeaders, reqBody) = await HttpLogHelper.CaptureAsync( + context.Request.Body, + context.Request.Headers, + normReqCt); + } + else + { + reqBody = LogFormatting.Omitted("non-text-or-large", + reqLen, + normReqCt, + LoggingOptions.RequestResponseBodyMaxBytes); + } var originalBody = context.Response.Body; - context.Response.Body = responseBuffer; + var tee = new CappedResponseBodyStream(originalBody, LoggingOptions.RequestResponseBodyMaxBytes); + context.Response.Body = tee; var sw = Stopwatch.GetTimestamp(); try @@ -45,42 +79,31 @@ public async Task InvokeAsync(HttpContext context) var elapsed = Stopwatch.GetElapsedTime(sw) .TotalMilliseconds; - var resContentType = context.Response.ContentType; - var isText = HttpLogHelper.IsTextLike(resContentType); - var bufferedLen = responseBuffer.Length; + var resCt = MediaTypeUtil.Normalize(context.Response.ContentType); + var isText = HttpLogHelper.IsTextLike(resCt); - string resHeaders, resBody; + object resHeaders = RedactionHelper.RedactHeaders(context.Response.Headers); + object resBody; - if (isText && bufferedLen <= LoggingOptions.RequestResponseBodyMaxBytes) + if (tee.TotalWritten == 0) { - using var ms = new MemoryStream(capacity: (int)Math.Min(bufferedLen, int.MaxValue)); - await responseBuffer.DrainBufferAsync(ms, context.RequestAborted); - - ms.Position = 0; + resBody = new Dictionary(); + } + else if (isText && tee.TotalWritten <= LoggingOptions.RequestResponseBodyMaxBytes) + { + using var ms = new MemoryStream(tee.Captured.ToArray()); (resHeaders, resBody) = await HttpLogHelper.CaptureAsync( ms, context.Response.Headers, - resContentType); - - ms.Position = 0; - await ms.CopyToAsync(originalBody, context.RequestAborted); + resCt); } else { - resHeaders = JsonSerializer.Serialize(RedactionHelper.RedactHeaders(context.Response.Headers)); - var reason = !isText - ? "non-text" - : bufferedLen > LoggingOptions.RequestResponseBodyMaxBytes - ? "exceeds-limit" - : "unknown-length"; - - resBody = JsonSerializer.Serialize( - HttpLogHelper.BuildOmittedBodyMessage(reason, - bufferedLen, - resContentType, - LoggingOptions.RequestResponseBodyMaxBytes)); - - await responseBuffer.DrainBufferAsync(originalBody, context.RequestAborted); + var reason = isText ? "exceeds-limit" : "non-text"; + resBody = LogFormatting.Omitted(reason, + tee.TotalWritten, + resCt, + LoggingOptions.RequestResponseBodyMaxBytes); } context.Response.Body = originalBody; @@ -102,14 +125,12 @@ public async Task InvokeAsync(HttpContext context) using (logger.BeginScope(scope)) { - // Distinct, human-readable prefix so it's unmistakably yours in Kibana logger.LogInformation( "[HTTP IN] {Method} {Path} -> {StatusCode} in {ElapsedMilliseconds}ms", context.Request.Method, context.Request.Path.Value, context.Response.StatusCode, - elapsed - ); + elapsed); } } } diff --git a/src/SharedKernel/Logging/Middleware/SignalRLoggingHubFilter.cs b/src/SharedKernel/Logging/Middleware/SignalRLoggingHubFilter.cs index be98343..85964b6 100644 --- a/src/SharedKernel/Logging/Middleware/SignalRLoggingHubFilter.cs +++ b/src/SharedKernel/Logging/Middleware/SignalRLoggingHubFilter.cs @@ -20,9 +20,8 @@ internal sealed class SignalRLoggingHubFilter(ILogger l var methodName = invocationContext.HubMethodName; // serialize + redact - var serializedArgs = JsonSerializer.Serialize(invocationContext.HubMethodArguments); - var redactedObj = RedactionHelper.RedactBody("application/json", serializedArgs); - var redactedArgs = JsonSerializer.Serialize(redactedObj); + var rawArgsJson = JsonSerializer.Serialize(invocationContext.HubMethodArguments); + var redactedArgsObj = RedactionHelper.RedactBody("application/json", rawArgsJson); // invoke the actual method var result = await next(invocationContext); @@ -32,7 +31,7 @@ internal sealed class SignalRLoggingHubFilter(ILogger l var scope = new Dictionary { - ["Args"] = redactedArgs, + ["Args"] = redactedArgsObj, ["Hub"] = hubName, ["ConnId"] = connId, ["UserId"] = userId, diff --git a/src/SharedKernel/SharedKernel.csproj b/src/SharedKernel/SharedKernel.csproj index 74fb10c..810f16a 100644 --- a/src/SharedKernel/SharedKernel.csproj +++ b/src/SharedKernel/SharedKernel.csproj @@ -8,13 +8,13 @@ Readme.md Pandatech MIT - 1.6.1 + 1.6.2 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 - Logging tuned and wording changed + Logging performance extreme boost and redesigned log structure