fix: route ITestOutput writes through synchronized ConcurrentStringWriter#5558
fix: route ITestOutput writes through synchronized ConcurrentStringWriter#5558
Conversation
…iter ITestOutput.WriteLine/WriteError used a plain StringWriter with no synchronization. Concurrent writes (e.g. from WebApplicationFactory background logging) and reads (GetStandardOutput calling ToString()) raced on the internal StringBuilder, causing intermittent ArgumentOutOfRangeException at StringBuilder.ToString(). Route through the base Context.OutputWriter/ErrorOutputWriter instead, which are ConcurrentStringWriter instances protected by ReaderWriterLockSlim. Remove the now-unnecessary _outputWriter and _errorWriter fields, and deduplicate GetOutput/GetOutputError into a shared CombineOutputs helper. Fixes #5556
|
Azure Pipelines: 1 pipeline(s) were filtered out due to trigger conditions. |
There was a problem hiding this comment.
Code Review
Summary: This PR fixes a legitimate thread-safety bug and simplifies the output collection logic. The approach is correct and the code is clean.
Bug Fix (Core Issue) — Correct
The root cause was that ITestOutput.WriteLine/WriteError was writing to a lazy-init StringWriter (_outputWriter/_errorWriter) with no synchronization, while GetOutput() read from it concurrently via _outputWriter.ToString() → StringBuilder.ToString(), causing the reported ArgumentOutOfRangeException. Routing through OutputWriter/ErrorOutputWriter (backed by ConcurrentStringWriter with ReaderWriterLockSlim) is the right fix.
CombineOutputs — One Minor Observation
if (string.IsNullOrEmpty(runtimeOutput))
{
return buildTimeOutput!; // null-forgiving operator is redundant here
}The ! on buildTimeOutput! at line 91 is unnecessary — string.IsNullOrEmpty(buildTimeOutput) already returned false at this point, so the compiler knows it's non-null. A trivial nit, no functional impact.
Behavior Change Worth Noting
Previously, ITestOutput.WriteLine output and console-intercepted output were collected in separate buckets (_outputWriter vs. the base OutputWriter), then concatenated in GetOutput(). Now both go into the same ConcurrentStringWriter, so they're interleaved in temporal order rather than grouped by source.
This is arguably better behavior (chronological ordering makes more sense), but it's a subtle observable change worth documenting in the PR description or a comment for anyone debugging output ordering in the future.
Missing Test Coverage
The test plan has an unchecked item:
[ ] Verify with ASP.NET Core WebApplicationFactory integration tests under parallel execution
This is the scenario that reproduces the original race. If an automated integration test can be added (even a simple stress test with Parallel.For calling ITestOutput.WriteLine and GetStandardOutput() concurrently), it would prevent regressions. The fix is correct, but without a test the race can silently reappear if the plumbing changes again.
Summary
The fix is well-targeted and the CombineOutputs refactor correctly preserves semantics for the two-source case. The removal of the redundant _outputWriter/_errorWriter fields is clean. The only meaningful ask is a regression test for the concurrent write scenario to lock in the fix long-term.
Code ReviewSummary: This PR fixes a legitimate thread-safety bug and simplifies the output collection logic. The approach is correct and the code is clean. Bug Fix (Core Issue) — CorrectThe root cause was that
|
Up to standards ✅🟢 Issues
|
| Metric | Results |
|---|---|
| Complexity | -10 |
TIP This summary will be updated as you push new changes. Give us feedback
…ding ClassHookContext, AssemblyHookContext, and TestSessionContext used plain HashSet/List for tracking children, accessed concurrently during parallel test building. HashSet.AddIfNotPresent corrupts internal state under concurrent access, throwing IndexOutOfRangeException. Add Lock to each context class protecting Add/Remove and snapshot the collections on read via [.. list] to prevent iteration races. Fixes IndexOutOfRangeException at HashSet.AddIfNotPresent in ContextProvider.CreateTestContext during parallel test discovery.
|
Azure Pipelines: 1 pipeline(s) were filtered out due to trigger conditions. |
There was a problem hiding this comment.
Code Review
The core fix is well-targeted and architecturally sound — routing ITestOutput.WriteLine/WriteError through the already-synchronized ConcurrentStringWriter (OutputWriter/ErrorOutputWriter) directly addresses the StringBuilder data race reported in #5556/#5411. Good root-cause analysis.
Issue: Cache Rebuild Outside Lock — Potential for Permanently Stale Data
Files: AssemblyHookContext.cs:44, TestSessionContext.cs:78-80
// AssemblyHookContext.cs
public IReadOnlyList<TestContext> AllTests => _cachedAllTests ??= TestClasses.SelectMany(x => x.Tests).ToArray();
// TestSessionContext.cs
public IReadOnlyList<ClassHookContext> TestClasses => _cachedTestClasses ??= Assemblies.SelectMany(x => x.TestClasses).ToArray();
public IReadOnlyList<TestContext> AllTests => _cachedAllTests ??= TestClasses.SelectMany(x => x.Tests).ToArray();InvalidateCaches() is correctly called under the lock. However, the ??= rebuilds happen outside the lock. This creates a TOCTOU window:
- Thread A sees
_cachedAllTests == null, starts computing the array - Thread B calls
AddClass→ acquires lock →InvalidateCaches()nulls the field → releases lock → adds the new class - Thread A completes computation with stale data (missing B's new class) and assigns it to
_cachedAllTests - No further invalidation is triggered → the cache is permanently stale
On x64/ARM64 the reference writes are individually atomic, so there is no torn read — but that doesn't save from the TOCTOU race. The stale value wins.
Better approach: Guard the rebuild inside the lock, or use a well-known lazy-init idiom:
// Option 1 – simplest fix: rebuild inside lock
public IReadOnlyList<TestContext> AllTests
{
get
{
lock (_lock)
{
return _cachedAllTests ??= TestClasses.SelectMany(x => x.Tests).ToArray();
}
}
}
// Option 2 – lock-free with Interlocked (avoids blocking readers):
public IReadOnlyList<TestContext> AllTests
{
get
{
var cached = Volatile.Read(ref _cachedAllTests);
if (cached is not null) return cached;
var computed = TestClasses.SelectMany(x => x.Tests).ToArray();
return Interlocked.CompareExchange(ref _cachedAllTests, computed, null) ?? computed;
}
}The Volatile.Read + Interlocked.CompareExchange approach preserves the lock-free read path and guarantees correct visibility without a mutex. This matters because AllTests and TestClasses are likely read frequently during parallel execution.
Minor: TestCount Allocates a Full Snapshot Just to Count
File: ClassHookContext.cs
public int TestCount => Tests.Count;Tests now returns [.. _tests] (a copy), so .Count creates a full list snapshot just to get the integer count. Instead:
public int TestCount { get { lock (_lock) return _tests.Count; } }Observation: TOCTOU Between empty Check and Parent Remove
Files: AssemblyHookContext.cs:55-68, ClassHookContext.cs:81-95
bool empty;
lock (_lock)
{
_testClasses.Remove(classContext);
empty = _testClasses.Count == 0;
}
if (empty) // ← window here
{
TestSessionContext.RemoveAssembly(this); // could be wrong by now
}Between releasing _lock and calling RemoveAssembly, another thread could AddClass to this assembly — making it non-empty again. The parent remove would then incorrectly evict a live, non-empty assembly from the session. The lock-then-call-out-of-lock approach is correct for avoiding lock ordering issues, but the emptiness decision is no longer valid by the time it's acted on. This is a pre-existing design problem (not introduced by this PR), but now that locking is added, it would be worth addressing with a double-check pattern or by letting the parent perform the remove decision.
What Works Well
- The primary fix is correct:
ConcurrentStringWriter(backed byReaderWriterLockSlim) properly serializes bothWriteand read (GetStandardOutput) operations. RoutingITestOutputwrites through it is the right fix. - C# 13
Locktype: Better than locking onobject— it's more efficient and documents intent. - Snapshot pattern
[.. _list]: Returning a copy fromTestClasses/Testsunder the lock prevents callers from mutating the internal list or iterating while another thread mutates. Clean. CombineOutputsrefactor: The three-source → two-source change is correct (the third was the now-removed_outputWriterthat flows intobase.GetStandardOutput()). The deduplication from ~40 lines to ~15 is a net improvement. The early-return optimizations (string.IsNullOrEmptyguards) avoidValueStringBuilderallocation for the common single-source case.bool emptypattern in Remove methods: Capturing the state inside the lock before acting outside is the right way to avoid holding multiple locks simultaneously.
The cache-rebuild issue is the most actionable concern — fixing it would make the threading model consistent throughout. Everything else is a minor polish.
Updated [TUnit](https://github.com/thomhurst/TUnit) from 1.33.0 to 1.35.2. <details> <summary>Release notes</summary> _Sourced from [TUnit's releases](https://github.com/thomhurst/TUnit/releases)._ ## 1.35.2 <!-- Release notes generated using configuration in .github/release.yml at v1.35.2 --> ## What's Changed ### Other Changes * fix: restore SourceLink and deterministic builds in published packages by @thomhurst in thomhurst/TUnit#5579 ### Dependencies * chore(deps): update tunit to 1.35.0 by @thomhurst in thomhurst/TUnit#5578 **Full Changelog**: thomhurst/TUnit@v1.35.0...v1.35.2 ## 1.35.0 <!-- Release notes generated using configuration in .github/release.yml at v1.35.0 --> ## What's Changed ### Other Changes * fix: support open generic transitive auto-mocks by @thomhurst in thomhurst/TUnit#5568 * refactor: separate test and lifecycle tracing by @thomhurst in thomhurst/TUnit#5572 * fix: expand nested And/Or expectations in failure messages (#5573) by @thomhurst in thomhurst/TUnit#5577 ### Dependencies * chore(deps): update tunit to 1.34.5 by @thomhurst in thomhurst/TUnit#5566 * chore(deps): bump follow-redirects from 1.15.11 to 1.16.0 in /docs by @dependabot[bot] in thomhurst/TUnit#5538 * chore(deps): update verify to 31.16.0 by @thomhurst in thomhurst/TUnit#5570 * chore(deps): update verify to 31.16.1 by @thomhurst in thomhurst/TUnit#5574 * chore(deps): update gittools/actions action to v4 by @thomhurst in thomhurst/TUnit#5575 **Full Changelog**: thomhurst/TUnit@v1.34.5...v1.35.0 ## 1.34.5 <!-- Release notes generated using configuration in .github/release.yml at v1.34.5 --> ## What's Changed ### Other Changes * fix: cap test output at 1M chars to prevent OOM by @thomhurst in thomhurst/TUnit#5561 * fix: handle explicit interface impl with different return types in mock generator by @thomhurst in thomhurst/TUnit#5564 * fix: include XML documentation files in NuGet packages by @thomhurst in thomhurst/TUnit#5565 ### Dependencies * chore(deps): update tunit to 1.34.0 by @thomhurst in thomhurst/TUnit#5562 **Full Changelog**: thomhurst/TUnit@v1.34.0...v1.34.5 ## 1.34.0 <!-- Release notes generated using configuration in .github/release.yml at v1.34.0 --> ## What's Changed ### Other Changes * refactor: move CorrelatedTUnitLogger to TUnit.Logging.Microsoft and auto-inject handlers by @thomhurst in thomhurst/TUnit#5532 * feat: add Dev Drive setup for Windows in CI workflow by @thomhurst in thomhurst/TUnit#5544 * fix: start session activity before discovery so discovery spans parent correctly by @thomhurst in thomhurst/TUnit#5534 * feat: cross-process test log correlation via OTLP receiver by @thomhurst in thomhurst/TUnit#5533 * refactor: use natural OTEL trace propagation instead of synthetic TraceIds by @thomhurst in thomhurst/TUnit#5557 * fix: route ITestOutput writes through synchronized ConcurrentStringWriter by @thomhurst in thomhurst/TUnit#5558 ### Dependencies * chore(deps): update tunit to 1.33.0 by @thomhurst in thomhurst/TUnit#5527 * chore(deps): update dependency dompurify to v3.4.0 by @thomhurst in thomhurst/TUnit#5537 * chore(deps): update dependency docusaurus-plugin-llms to ^0.3.1 by @thomhurst in thomhurst/TUnit#5541 * chore(deps): update dependency microsoft.sourcelink.github to 10.0.202 by @thomhurst in thomhurst/TUnit#5543 * chore(deps): update dependency microsoft.entityframeworkcore to 10.0.6 by @thomhurst in thomhurst/TUnit#5542 * chore(deps): update dependency microsoft.templateengine.authoring.templateverifier to 10.0.202 by @thomhurst in thomhurst/TUnit#5546 * chore(deps): update dependency microsoft.templateengine.authoring.cli to v10.0.202 by @thomhurst in thomhurst/TUnit#5545 * chore(deps): update dependency system.commandline to 2.0.6 by @thomhurst in thomhurst/TUnit#5547 * chore(deps): update microsoft.aspnetcore to 10.0.6 by @thomhurst in thomhurst/TUnit#5548 * chore(deps): update dependency nuget.protocol to 7.3.1 by @thomhurst in thomhurst/TUnit#5549 * chore(deps): update microsoft.extensions to 10.0.6 by @thomhurst in thomhurst/TUnit#5550 * chore(deps): update dependency dotnet-sdk to v10.0.202 by @thomhurst in thomhurst/TUnit#5551 * chore(deps): update opentelemetry by @thomhurst in thomhurst/TUnit#5552 * chore(deps): update microsoft.extensions to 10.5.0 by @thomhurst in thomhurst/TUnit#5554 **Full Changelog**: thomhurst/TUnit@v1.33.0...v1.34.0 Commits viewable in [compare view](thomhurst/TUnit@v1.33.0...v1.35.2). </details> [](https://docs.github.com/en/github/managing-security-vulnerabilities/about-dependabot-security-updates#about-compatibility-scores) Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting `@dependabot rebase`. [//]: # (dependabot-automerge-start) [//]: # (dependabot-automerge-end) --- <details> <summary>Dependabot commands and options</summary> <br /> You can trigger Dependabot actions by commenting on this PR: - `@dependabot rebase` will rebase this PR - `@dependabot recreate` will recreate this PR, overwriting any edits that have been made to it - `@dependabot show <dependency name> ignore conditions` will show all of the ignore conditions of the specified dependency - `@dependabot ignore this major version` will close this PR and stop Dependabot creating any more for this major version (unless you reopen the PR or upgrade to it yourself) - `@dependabot ignore this minor version` will close this PR and stop Dependabot creating any more for this minor version (unless you reopen the PR or upgrade to it yourself) - `@dependabot ignore this dependency` will close this PR and stop Dependabot creating any more for this dependency (unless you reopen the PR or upgrade to it yourself) </details> Signed-off-by: dependabot[bot] <support@github.com> Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Summary
ITestOutput.WriteLine/WriteErrorused a plainStringWriter(_outputWriter/_errorWriter) with no synchronization. Concurrent writes and reads (viaGetStandardOutput()callingStringBuilder.ToString()) raced on the internalStringBuilder, causing intermittentArgumentOutOfRangeExceptionatStringBuilder.ToString()— the same crash reported in Flaky ArgumentOutOfRangeException in StringBuilder.ToString() during parallel test execution #5411 that resurfaced.Context.OutputWriter/ErrorOutputWriter, which areConcurrentStringWriterinstances already protected byReaderWriterLockSlim. Remove the now-redundant_outputWriter/_errorWriterfields.GetOutput()/GetOutputError()into a sharedCombineOutputshelper (was ~40 lines of near-identical code).Test plan
TUnit.UnitTests— 177/177 passWebApplicationFactoryintegration tests under parallel execution (reproduces the original race)Fixes #5556