Skip to content

P3: Add LoggingHandler with structured logging and sensitive data redaction#1

Merged
jhosm merged 2 commits intomainfrom
feature/p3-logging-handler
Feb 12, 2026
Merged

P3: Add LoggingHandler with structured logging and sensitive data redaction#1
jhosm merged 2 commits intomainfrom
feature/p3-logging-handler

Conversation

@jhosm
Copy link
Owner

@jhosm jhosm commented Feb 9, 2026

Summary

  • Adds AcdcLoggingOptions configuration (now a record with FrozenSet defaults) with configurable thresholds and 16 default sensitive field names
  • Adds SensitiveDataRedactor for redacting headers, query parameters, and JSON body fields (case-insensitive matching via System.Text.Json)
  • Adds LoggingHandler (DelegatingHandler) with structured request/response logging, slow request and large payload warnings, AsyncLocal reentrancy prevention, and per-request SkipLogging opt-out
  • Adds comprehensive unit tests for both SensitiveDataRedactor (18 tests) and LoggingHandler (18 tests)

Review feedback addressed

  • Converted AcdcLoggingOptions to record with FrozenSet for immutable defaults
  • Protected HTTP pipeline from logging/redaction failures (try/catch with graceful degradation)
  • Defensive copy of SensitiveFields in SensitiveDataRedactor with forced OrdinalIgnoreCase
  • Added ArgumentNullException.ThrowIfNull() null guards in constructors
  • OperationCanceledException now logged at Information level (not Error)
  • Non-JSON bodies return placeholder [non-JSON body, redaction skipped] instead of leaking raw content
  • Fixed repeated query parameter handling via GetValues()
  • Added null-check for response.Content?.Headers.ContentLength
  • Renamed IsLogging_isLogging (naming convention)
  • Fixed .GetAwaiter().GetResult() → proper await in reentrancy test
  • Removed unused usings, added using var for disposables
  • Added tests: AsyncLocal error recovery, concurrent request isolation, cancellation logging
  • Improved reentrancy test with InnerLogger assertion
  • Enhanced response header redaction test with sensitive header assertion

Test plan

  • All 138 tests pass (existing P2 tests + updated P3 tests)
  • Build succeeds with TreatWarningsAsErrors enabled (0 warnings)
  • Verified case-insensitive redaction for all 16 default sensitive fields
  • Verified reentrancy prevention with nested request test + inner logger assertion
  • Verified per-request SkipLogging opt-out
  • Verified slow request and large payload threshold boundary behavior
  • Verified AsyncLocal resets after error
  • Verified concurrent requests log independently
  • Verified cancellation logged at Information, not Error
  • Verified response headers with sensitive fields are redacted
  • Verified non-JSON body returns placeholder instead of raw content

🤖 Generated with Claude Code

…ta redaction

- Add AcdcLoggingOptions with configurable slow request threshold (3s default),
  large payload threshold (1 MiB), and 16 default sensitive field names
- Add SensitiveDataRedactor for header, query parameter, and JSON body redaction
  with case-insensitive field matching via System.Text.Json
- Add LoggingHandler DelegatingHandler with request/response logging at Info level,
  slow request warnings, large payload warnings, error logging with redacted details,
  AsyncLocal<bool> reentrancy prevention, and per-request SkipLogging opt-out
- Add comprehensive unit tests for both SensitiveDataRedactor and LoggingHandler
  covering all redaction scenarios, threshold boundaries, reentrancy, and error paths

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Copilot AI review requested due to automatic review settings February 9, 2026 00:21
Copy link

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Adds structured HTTP request/response logging to the CSharpAcdc HTTP pipeline, including configurable thresholds and a reusable sensitive-data redactor to prevent leaking secrets in logs.

Changes:

  • Introduces AcdcLoggingOptions for slow-request / large-payload thresholds and a default sensitive field set.
  • Adds SensitiveDataRedactor to redact sensitive headers, query parameters, and JSON body fields.
  • Adds LoggingHandler (DelegatingHandler) plus unit tests for both the handler and the redactor.

Reviewed changes

Copilot reviewed 5 out of 5 changed files in this pull request and generated 13 comments.

Show a summary per file
File Description
src/CSharpAcdc/Configuration/AcdcLoggingOptions.cs Adds configuration for logging thresholds and default sensitive fields.
src/CSharpAcdc/Logging/SensitiveDataRedactor.cs Implements header/query/JSON redaction logic.
src/CSharpAcdc/Handlers/LoggingHandler.cs Adds request/response structured logging and warning logic.
tests/CSharpAcdc.Tests/Logging/SensitiveDataRedactorTests.cs Adds unit tests covering redaction behaviors.
tests/CSharpAcdc.Tests/Handlers/LoggingHandlerTests.cs Adds unit tests for logging, redaction, warnings, and reentrancy behavior.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

using FluentAssertions;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using NSubstitute;
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unused using NSubstitute; will produce CS8019 (unnecessary using directive) and can fail builds when warnings are treated as errors. Remove this using if it’s not needed.

Suggested change
using NSubstitute;

Copilot uses AI. Check for mistakes.

// Should see request + response logs for outer, but not for inner
infoLogs.Should().AllSatisfy(e => e.Message.Should().Contain("/outer"));
infoLogs.Should().NotContain(e => e.Message.Contains("/inner"));
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This reentrancy test doesn’t currently validate whether the nested request was actually skipped: the inner request logs would go to innerLogger, but the assertions only inspect the outer _logger, so it would pass even if the reentrancy guard failed. Expose innerLogger to the test (e.g., via a field on NestedRequestHandler) and assert it has no entries (or explicitly assert expected counts).

Suggested change
infoLogs.Should().NotContain(e => e.Message.Contains("/inner"));
infoLogs.Should().NotContain(e => e.Message.Contains("/inner"));
// Additionally ensure the nested handler's own logger did not record any entries
nestedHandler.InnerLogger.Entries.Should().BeEmpty();

Copilot uses AI. Check for mistakes.
Comment on lines 368 to 371
// This should be skipped by reentrancy guard
_ = innerClient.GetAsync("/inner", cancellationToken).GetAwaiter().GetResult();

return Task.FromResult(new HttpResponseMessage(HttpStatusCode.OK));
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Calling GetAsync(...).GetAwaiter().GetResult() from within a handler can deadlock under certain synchronization contexts and can also block threadpool threads unnecessarily. Make this override async and await the nested call instead.

Copilot uses AI. Check for mistakes.
Comment on lines 46 to 48
redactedParts.Add(IsSensitive(name)
? $"{Uri.EscapeDataString(name)}={Redacted}"
: $"{Uri.EscapeDataString(name)}={Uri.EscapeDataString(query[name] ?? string.Empty)}");
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

HttpUtility.ParseQueryString collapses repeated query keys (e.g., a=1&a=2) into a single comma-separated string via query[name], and this implementation will log it as a single value (and after escaping, it becomes 1%2C2). If preserving query shape matters for debugging, iterate query.GetValues(name) and emit one name=value pair per value while still redacting sensitive keys.

Suggested change
redactedParts.Add(IsSensitive(name)
? $"{Uri.EscapeDataString(name)}={Redacted}"
: $"{Uri.EscapeDataString(name)}={Uri.EscapeDataString(query[name] ?? string.Empty)}");
var values = query.GetValues(name);
var escapedName = Uri.EscapeDataString(name);
if (IsSensitive(name))
{
if (values is null || values.Length == 0)
{
redactedParts.Add($"{escapedName}={Redacted}");
}
else
{
foreach (var _ in values)
{
redactedParts.Add($"{escapedName}={Redacted}");
}
}
}
else
{
if (values is null || values.Length == 0)
{
redactedParts.Add($"{escapedName}=");
}
else
{
foreach (var value in values)
{
redactedParts.Add($"{escapedName}={Uri.EscapeDataString(value ?? string.Empty)}");
}
}
}

Copilot uses AI. Check for mistakes.
Comment on lines 11 to 13
{
private static readonly AsyncLocal<bool> IsLogging = new();

Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Private field naming deviates from the repository’s naming rules (private fields should be prefixed with '_' and camelCase). Rename this static field (e.g., to '_isLogging') to satisfy the analyzer rules in .editorconfig and avoid style warnings becoming build breaks under TreatWarningsAsErrors.

Copilot uses AI. Check for mistakes.
mockHandler.When("*").Respond(HttpStatusCode.OK);

using var client = CreateClient(mockHandler);
var request = new HttpRequestMessage(HttpMethod.Get, "/test");
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Disposable 'HttpRequestMessage' is created but not disposed.

Suggested change
var request = new HttpRequestMessage(HttpMethod.Get, "/test");
using var request = new HttpRequestMessage(HttpMethod.Get, "/test");

Copilot uses AI. Check for mistakes.
mockHandler.When("*").Respond(HttpStatusCode.OK);

using var client = CreateClient(mockHandler, options);
var request = new HttpRequestMessage(HttpMethod.Get, "/test");
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Disposable 'HttpRequestMessage' is created but not disposed.

Suggested change
var request = new HttpRequestMessage(HttpMethod.Get, "/test");
using var request = new HttpRequestMessage(HttpMethod.Get, "/test");

Copilot uses AI. Check for mistakes.
mockHandler.When("*").Respond(HttpStatusCode.OK);

using var client = CreateClient(mockHandler, options);
var content = new StringContent(new string('x', 200));
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Disposable 'StringContent' is created but not disposed.

Suggested change
var content = new StringContent(new string('x', 200));
using var content = new StringContent(new string('x', 200));

Copilot uses AI. Check for mistakes.
mockHandler.When("*").Respond(HttpStatusCode.OK);

using var client = CreateClient(mockHandler);
var request = new HttpRequestMessage(HttpMethod.Get, "/silent");
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Disposable 'HttpRequestMessage' is created but not disposed.

Suggested change
var request = new HttpRequestMessage(HttpMethod.Get, "/silent");
using var request = new HttpRequestMessage(HttpMethod.Get, "/silent");

Copilot uses AI. Check for mistakes.
// This should be skipped by reentrancy guard
_ = innerClient.GetAsync("/inner", cancellationToken).GetAwaiter().GetResult();

return Task.FromResult(new HttpResponseMessage(HttpStatusCode.OK));
Copy link

Copilot AI Feb 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Disposable 'HttpResponseMessage' is created but not disposed.

Copilot uses AI. Check for mistakes.
@jhosm
Copy link
Owner Author

jhosm commented Feb 9, 2026

Code review

No issues found. Checked for bugs and CLAUDE.md compliance.

🤖 Generated with Claude Code

@jhosm
Copy link
Owner Author

jhosm commented Feb 9, 2026

Comprehensive PR Review -- P3: LoggingHandler

Five specialized review agents independently analyzed this PR. Below is the deduplicated, aggregated summary.


Critical Issues

1. AcdcLoggingOptions is a mutable class -- violates CLAUDE.md convention (3 agents converged)

CLAUDE.md states: "Use record types for DTOs and immutable config." AcdcLoggingOptions is configuration with public { get; set; } properties. All three properties can be mutated after construction, including replacing SensitiveFields with a case-sensitive set (breaking redaction). In a concurrent server context with pooled DelegatingHandler instances, this is both a convention violation and a thread-safety hazard.

public class AcdcLoggingOptions
{
public TimeSpan SlowRequestThreshold { get; set; } = TimeSpan.FromSeconds(3);
public long LargePayloadThreshold { get; set; } = 1_048_576; // 1 MiB
public IReadOnlySet<string> SensitiveFields { get; set; } = new HashSet<string>(StringComparer.OrdinalIgnoreCase)
{

Type design scores: Encapsulation 2/10, Invariant Expression 2/10, Enforcement 1/10.

Fix: Convert to record with init setters, or at minimum add IValidateOptions<T> validation and freeze SensitiveFields internally.


2. Unprotected redaction/logging can crash the HTTP pipeline (2 agents)

_redactor.RedactUrl(), _redactor.RedactHeaders(), and _logger.Log*() are all called without try/catch. If redaction throws (e.g., UriFormatException on malformed URI) or the logger throws (sink serialization failure), the user's HTTP request fails -- not because of a network problem, but because the logging infrastructure crashed. A logging handler should never take down the pipeline.

var redactedUrl = _redactor.RedactUrl(request.RequestUri);
var redactedHeaders = _redactor.RedactHeaders(request.Headers);
_logger.LogInformation(
"HTTP {Method} {Url} Headers: {Headers}",
request.Method,
redactedUrl,
redactedHeaders);

Fix: Wrap pre-request and post-response logging blocks in try/catch that degrades gracefully.


3. Invalid JSON silently returned unredacted -- sensitive data leak risk (2 agents)

When RedactJsonBody fails to parse JSON, it silently returns the original body unredacted. A body with a minor JSON syntax error containing password, token, api_key fields will be logged in full with all secrets visible. No warning is emitted.

}
catch (JsonException)
{
return body; // Not valid JSON — return as-is
}

Fix: Either return [non-JSON body, redaction skipped] placeholder, or add ILogger to SensitiveDataRedactor and log a warning when redaction is skipped.


Important Issues

4. No defensive copy of SensitiveFields set (3 agents)

SensitiveDataRedactor stores a reference to options.SensitiveFields without copying. External code can cast IReadOnlySet<string> back to HashSet<string> and mutate it, or the AcdcLoggingOptions setter can replace it entirely. Under concurrency, this is a data race.

private const string Redacted = "[REDACTED]";
private readonly IReadOnlySet<string> _sensitiveFields;
public SensitiveDataRedactor(AcdcLoggingOptions options)

Fix: Defensively copy in constructor: _sensitiveFields = new HashSet<string>(options.SensitiveFields, StringComparer.OrdinalIgnoreCase).


5. Missing constructor null guards (2 agents)

Neither LoggingHandler nor SensitiveDataRedactor validate constructor parameters. new LoggingHandler(null!, ...) defers the NullReferenceException to the first request instead of failing fast at construction.

Fix: Add ArgumentNullException.ThrowIfNull() in constructors.


6. OperationCanceledException logged at Error level (2 agents)

The catch block in SendWithLoggingAsync catches all Exception types and logs at LogError. Deliberate cancellation is expected behavior, not an error -- it pollutes error monitoring with false positives.

catch (Exception ex)
{
stopwatch.Stop();
_logger.LogError(
ex,
"HTTP {Method} {Url} failed after {ElapsedMs}ms",
request.Method,
redactedUrl,
stopwatch.ElapsedMilliseconds);
throw;
}

Fix: Add a separate catch (OperationCanceledException) that logs at Information/Debug level before the general catch (Exception).


7. .GetAwaiter().GetResult() blocking call in test (2 agents)

NestedRequestHandler.SendAsync uses .GetAwaiter().GetResult() which violates the "Async all the way" CLAUDE.md rule and risks deadlocks. While the synchronous call is deliberate for AsyncLocal testing, it needs a comment explaining why await is not used.

// This should be skipped by reentrancy guard
_ = innerClient.GetAsync("/inner", cancellationToken).GetAwaiter().GetResult();


8. Contradictory comment block in NestedRequestHandler (comment-analyzer)

Lines 343-350 contain a paragraph describing an abandoned approach, followed by "But for a proper test, we actually construct an inner pipeline:" -- contradicting the preceding text. This is a draft-then-revise artifact.

// The reentrancy check happens in LoggingHandler. Since we're inside the
// outer LoggingHandler's SendAsync, the AsyncLocal<bool> IsLogging is true.
// We simulate the inner handler returning without actually nesting a second
// LoggingHandler (which would require constructing one and calling it).
// Instead, we validate that the flag is visible by checking it indirectly
// through the test's log count.
// But for a proper test, we actually construct an inner pipeline:


Test Coverage Gaps (Severity 7+)

Gap Severity Description
AsyncLocal reset after error 9/10 No test verifies IsLogging resets to false when base.SendAsync throws
SuppressLogging vs SkipLogging 8/10 Spec says SuppressLogging option, code uses SkipLogging -- naming mismatch
Custom fields replace vs merge 8/10 Setting custom SensitiveFields replaces all defaults, but no test verifies this behavior is intentional
Concurrent request isolation 7/10 No test verifies two parallel requests log independently without cross-contamination
Response header redaction 7/10 Response headers are redacted in code but no test asserts this

Strengths

  • AsyncLocal<bool> reentrancy guard with try/finally is a thoughtful design choice
  • No per-request state in instance fields -- correctly follows IHttpClientFactory handler pooling model
  • ConfigureAwait(false) used consistently
  • SensitiveDataRedactor.RedactJsonBody catch block is narrowly typed to JsonException
  • Comprehensive default sensitive fields list (16 fields covering common secrets)
  • ShouldSkip method provides clean per-request opt-out mechanism
  • 33 tests covering both SensitiveDataRedactor and LoggingHandler

Type Design Summary

Type Encapsulation Invariant Expression Usefulness Enforcement
AcdcLoggingOptions 2/10 2/10 7/10 1/10
SensitiveDataRedactor 6/10 5/10 8/10 3/10
LoggingHandler 7/10 6/10 9/10 5/10

Recommended Action Plan

  1. Harden AcdcLoggingOptions: Convert to record or add init setters + validation
  2. Protect the pipeline: Wrap logging operations so they cannot crash HTTP requests
  3. Defensive copy: Copy SensitiveFields in SensitiveDataRedactor constructor with forced OrdinalIgnoreCase
  4. Add null guards: ArgumentNullException.ThrowIfNull() in constructors
  5. Handle cancellation separately: Log OperationCanceledException at Information, not Error
  6. Address JSON fallback: Either placeholder or log warning when body cannot be parsed for redaction
  7. Add missing tests: AsyncLocal error recovery, concurrent isolation, response header redaction
  8. Clean up comments: Remove contradictory NestedRequestHandler comment block

Generated by 5 specialized review agents (code-reviewer, test-analyzer, silent-failure-hunter, type-design-analyzer, comment-analyzer).

🤖 Generated with Claude Code

If this review was useful, please react with 👍. Otherwise, react with 👎.

- Convert AcdcLoggingOptions to record with FrozenSet defaults
- Protect HTTP pipeline from logging/redaction failures (try/catch)
- Defensive copy of SensitiveFields with forced OrdinalIgnoreCase
- Add ArgumentNullException.ThrowIfNull in constructors
- Log OperationCanceledException at Information, not Error
- Return placeholder for non-JSON bodies instead of leaking raw content
- Fix repeated query param handling via GetValues()
- Add null-check for response.Content
- Rename IsLogging to _isLogging (naming convention)
- Fix GetAwaiter().GetResult() to async/await in test
- Remove unused usings, add using var for disposables
- Add tests: AsyncLocal error recovery, concurrent isolation, cancellation
- Improve reentrancy test with InnerLogger assertion
- Enhance response header redaction test with sensitive header assertion

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
@jhosm jhosm merged commit ca5d6e2 into main Feb 12, 2026
1 check passed
@jhosm jhosm deleted the feature/p3-logging-handler branch February 12, 2026 07:27
@jhosm jhosm mentioned this pull request Feb 14, 2026
4 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant