Skip to content

Route HTTP request logs to test output - #1513

Merged
SapiensAnatis merged 3 commits into
mainfrom
test/test-logger
Jul 4, 2026
Merged

Route HTTP request logs to test output#1513
SapiensAnatis merged 3 commits into
mainfrom
test/test-logger

Conversation

@SapiensAnatis

Copy link
Copy Markdown
Owner

Our integration tests spin up a single HTTP server and send parallel requests to it as different users, for performance reasons. This unfortunately makes it hard to associate logs to any particular test run: parallelism means that if you just capture stdout, you will start to see logs from other tests that ran at the same time.

This is a little experiment to see if we can make a 'smart' logger that uses a HTTP header to redirect output to the appropriate test.

@SapiensAnatis

Copy link
Copy Markdown
Owner Author

@claude review these changes

@claude

claude Bot commented Jul 4, 2026

Copy link
Copy Markdown

Claude finished @SapiensAnatis's task in 2m 23s —— View job


Reviewing PR #1513

  • Gather context (read changed files)
  • Review TestOutputSink.cs (new file)
  • Review CustomWebApplicationFactory.cs changes
  • Review HttpClientExtensions.cs changes
  • Review TestFixture.cs changes
  • Post final review

Neat approach — using the ambient TestContext.Current where available and falling back to a header-tagged lookup for request-thread logs is a reasonable way to solve the parallel-server-shared-logs problem without restructuring the test host per test.

Findings

1. Body-less PostMsgpack overload never tags the request (bug)HttpClientExtensions.cs:52-79
The single-argument PostMsgpack<TResponse>(string endpoint, ...) overload (no request body) calls client.PostAsync(endpoint, null, ...) directly and never goes through CreateMsgpackContent, so the Xunit-Test-Id header is never added. Any log emitted while handling one of these requests will fail ResolveOutputHelper (no ambient TestContext, no header) and get silently dropped in TestOutputSink.Emit. This overload is used at least once today (SavefileUpdateTestFixture.cs:38this.Client.PostMsgpack<LoadIndexResponse>("load/index")), so that call's server-side logs are currently unroutable.
Suggested fix: have this overload build an empty/tagged HttpContent via a shared helper (or just call CreateMsgpackContent with an empty payload) so the header gets attached consistently, or set Xunit-Test-Id as a default header on the HttpClient itself in TestFixture.CreateClient (TestFixture.cs:184-202) so it's attached to every request regardless of which method sends it — this would also make the mechanism robust against future extension methods that bypass CreateMsgpackContent.
Fix this →

2. TestOutputSink.OutputHelpers entries are never removedOther/TestOutputSink.cs:25,41-42
Register adds to the static ConcurrentDictionary but nothing ever removes an entry once a test finishes (there's no Unregister/dispose hook in TestFixture). This is bounded by the total number of tests in the run so it's unlikely to cause real problems today, but it does mean every ITestOutputHelper created over the life of the test process is kept reachable and the dictionary only grows. Minor — worth a follow-up if the suite grows significantly, e.g. removing the entry when the owning test completes (via TestContext.Current.TestOutputHelper disposal, if xUnit exposes a hook) or periodically pruning.

3. Non-HTTP-triggered logs are silently droppedOther/TestOutputSink.cs:44-64
Any log emitted from a background thread that isn't the test's own thread and doesn't carry an HttpContext (e.g. Hangfire jobs, fire-and-forget background tasks) will hit neither branch in ResolveOutputHelper and be silently swallowed. That's likely an acceptable, intentional limitation given the scope of this change (HTTP request logs specifically, per the PR title) — just flagging it so it's a conscious tradeoff rather than a surprise later if someone expects background-job logs to show up too.

Verification

  • dotnet csharpier check passes on all 4 changed files.
  • Wasn't able to get a full dotnet build/test run to completion in this sandbox — the checkout here is a shallow clone and Nerdbank.GitVersioning fails trying to compute version height (MSB4018, unrelated to this PR's code). The changes look correct on manual read-through, but you may want to confirm the integration test suite passes in CI.

Otherwise this is a well-scoped, well-commented addition — the docstrings on TestOutputSink clearly explain the two resolution paths and why the header fallback is needed.

@claude

claude Bot commented Jul 4, 2026

Copy link
Copy Markdown

Claude finished @SapiensAnatis's task in 4m 27s —— View job


Reviewing new commits on PR #1513

  • Gather context (diff since last review: eb616b2..HEAD, commits "Improvements" and "Dispose fix")
  • Review "Improvements" commit
  • Review "Dispose fix" commit
  • Post findings

Both findings from the initial review have been addressed properly:

  1. Body-less PostMsgpack overload never tagging requests — fixed by moving the Xunit-Test-Id header onto the HttpClient itself as a default header in TestFixture.CreateClient (TestFixture.cs:201-204), so it's now attached regardless of which extension method sends the request. The old per-call header logic in CreateMsgpackContent was correctly removed (HttpClientExtensions.cs).
  2. OutputHelpers entries never removed — fixed via TestOutputSink.Deregister (Other/TestOutputSink.cs:50-53), called from the new TestFixture.Dispose() (TestFixture.cs:339-357) which mirrors the Register call made in the constructor. Since TestFixture is the base class each test class derives from, xUnit creates/disposes one instance per test method, so Register/Deregister stay correctly paired per-test.

I also checked for a couple of related risks and didn't find problems:

  • The "Improvements" commit's Dispose() briefly disposed the shared CustomWebApplicationFactory on every test teardown, which would have torn down the shared web host after the first test — but this was caught and corrected in the very next "Dispose fix" commit (now correctly disposes only Client/ApiContext and leaves factory alone, with a comment explaining why).
  • Removing the try/catch (InvalidOperationException) around outputHelper.Write() in Emit looks safe: since Deregister now runs synchronously inside Dispose() (still within the test's valid ITestOutputHelper lifetime per xUnit's contract), there's no longer a window where a stale-but-still-registered helper can be looked up and then throw — a miss now cleanly falls through to TestContext.Current.SendDiagnosticMessage(...) instead.
  • Unrouteable/background logs (previously silently dropped, per finding Mostly done but untested fix_exec #3 in the original review) are now surfaced via SendDiagnosticMessage rather than swallowed — a nice incidental improvement.

No new issues found in these two commits.

@SapiensAnatis
SapiensAnatis merged commit 68829ae into main Jul 4, 2026
7 checks passed
@SapiensAnatis
SapiensAnatis deleted the test/test-logger branch July 4, 2026 23:43
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