From 0eff72829782ef7512742eecdf6d441e25bd9e9d Mon Sep 17 00:00:00 2001 From: Tom Longhurst <30480171+thomhurst@users.noreply.github.com> Date: Sat, 14 Feb 2026 12:22:56 +0000 Subject: [PATCH 1/8] fix: run data source initialization outside test timeout scope When a [ClassDataSource(Shared = SharedType.PerTestSession)] fixture implements IAsyncInitializer, its InitializeAsync() was running inside the timeout wrapper of whichever test triggered it first. If that test had a short [Timeout], the fixture initialization would get cancelled, causing ALL tests sharing the fixture to fail. Split the slow path (retry + timeout) in TestCoordinator so that: - Phase 1 (outside timeout): instance creation, skip check, prepare, and data source initialization run with the original cancellation token, not the timeout-linked one - Phase 2 (inside timeout): only the test body and hooks run under the test's timeout Also route console output during initialization to the real console (via GlobalContext) instead of capturing it in a test's output buffer. Fixes #4772 Co-Authored-By: Claude Opus 4.6 --- TUnit.Engine/Logging/TestOutputSink.cs | 34 +++++- .../Services/TestExecution/TestCoordinator.cs | 111 ++++++++++++++++-- TUnit.Engine/TestExecutor.cs | 11 +- 3 files changed, 141 insertions(+), 15 deletions(-) diff --git a/TUnit.Engine/Logging/TestOutputSink.cs b/TUnit.Engine/Logging/TestOutputSink.cs index 7f7426e843..a2ff518bb2 100644 --- a/TUnit.Engine/Logging/TestOutputSink.cs +++ b/TUnit.Engine/Logging/TestOutputSink.cs @@ -19,13 +19,45 @@ public void Log(LogLevel level, string message, Exception? exception, Context? c return; } + // During non-test phases (e.g. data source initialization), write directly to console + // since the output isn't associated with any specific test + if (context is GlobalContext globalContext) + { + var consoleWriter = level >= LogLevel.Error + ? globalContext.OriginalConsoleError + : globalContext.OriginalConsoleOut; + consoleWriter.WriteLine(message); + return; + } + var writer = level >= LogLevel.Error ? context.ErrorOutputWriter : context.OutputWriter; writer.WriteLine(message); } public ValueTask LogAsync(LogLevel level, string message, Exception? exception, Context? context) { - Log(level, message, exception, context); + if (context == null) + { + return ValueTask.CompletedTask; + } + + // During non-test phases (e.g. data source initialization), write directly to console + // since the output isn't associated with any specific test + if (context is GlobalContext globalContext) + { + var consoleWriter = level >= LogLevel.Error + ? globalContext.OriginalConsoleError + : globalContext.OriginalConsoleOut; + return WriteLineAsync(consoleWriter, message); + } + + var writer = level >= LogLevel.Error ? context.ErrorOutputWriter : context.OutputWriter; + writer.WriteLine(message); return ValueTask.CompletedTask; } + + private static async ValueTask WriteLineAsync(TextWriter writer, string message) + { + await writer.WriteLineAsync(message).ConfigureAwait(false); + } } diff --git a/TUnit.Engine/Services/TestExecution/TestCoordinator.cs b/TUnit.Engine/Services/TestExecution/TestCoordinator.cs index 2a761b8f15..507a87490c 100644 --- a/TUnit.Engine/Services/TestExecution/TestCoordinator.cs +++ b/TUnit.Engine/Services/TestExecution/TestCoordinator.cs @@ -113,17 +113,60 @@ private async ValueTask ExecuteTestInternalAsync(AbstractExecutableTest test, Ca else { // Slow path: use retry and timeout wrappers + // Data source initialization runs OUTSIDE the timeout so it doesn't + // count against the test's timeout (fixes #4772) await RetryHelper.ExecuteWithRetry(test.Context, async () => { - var timeoutMessage = testTimeout.HasValue - ? $"Test '{test.Context.Metadata.TestDetails.TestName}' timed out after {testTimeout.Value}" - : null; - - await TimeoutHelper.ExecuteWithTimeoutAsync( - ct => ExecuteTestLifecycleAsync(test, ct).AsTask(), - testTimeout, - cancellationToken, - timeoutMessage).ConfigureAwait(false); + // Phase 1: Instance creation and initialization OUTSIDE timeout + var shouldExecute = await PrepareAndInitializeOutsideTimeoutAsync(test, cancellationToken).ConfigureAwait(false); + + if (!shouldExecute) + { + return; + } + + // Phase 2: Test execution INSIDE timeout + try + { + var timeoutMessage = testTimeout.HasValue + ? $"Test '{test.Context.Metadata.TestDetails.TestName}' timed out after {testTimeout.Value}" + : null; + + await TimeoutHelper.ExecuteWithTimeoutAsync( + ct => _testExecutor.ExecuteAsync(test, _testInitializer, ct, skipInitialization: true).AsTask(), + testTimeout, + cancellationToken, + timeoutMessage).ConfigureAwait(false); + } + finally + { + // Dispose test instance and fire OnDispose after each attempt + // This ensures each retry gets a fresh instance + var onDispose = test.Context.InternalEvents.OnDispose; + if (onDispose?.InvocationList != null) + { + foreach (var invocation in onDispose.InvocationList) + { + try + { + await invocation.InvokeAsync(test.Context, test.Context).ConfigureAwait(false); + } + catch (Exception disposeEx) + { + await _logger.LogErrorAsync($"Error during OnDispose for {test.TestId}: {disposeEx}").ConfigureAwait(false); + } + } + } + + try + { + await TestExecutor.DisposeTestInstance(test).ConfigureAwait(false); + } + catch (Exception disposeEx) + { + await _logger.LogErrorAsync($"Error disposing test instance for {test.TestId}: {disposeEx}").ConfigureAwait(false); + } + } }).ConfigureAwait(false); } @@ -254,9 +297,57 @@ await _eventReceiverOrchestrator.InvokeLastTestInSessionEventReceiversAsync( } } + /// + /// Phase 1 of the slow path: creates the test instance, checks for skip, prepares and + /// initializes data sources. Runs OUTSIDE the timeout wrapper so data source initialization + /// does not count against the test's timeout (fixes #4772). + /// Console output during initialization goes to GlobalContext (real console) instead of + /// being captured in the test's output buffer. + /// + /// true if the test should proceed to execution; false if it was skipped. + private async ValueTask PrepareAndInitializeOutsideTimeoutAsync(AbstractExecutableTest test, CancellationToken cancellationToken) + { + test.Context.Metadata.TestDetails.ClassInstance = await test.CreateInstanceAsync().ConfigureAwait(false); + + // Invalidate cached eligible event objects since ClassInstance changed + test.Context.CachedEligibleEventObjects = null; + + // Check if this test should be skipped (after creating instance) + if (test.Context.Metadata.TestDetails.ClassInstance is SkippedTestInstance || + !string.IsNullOrEmpty(test.Context.SkipReason)) + { + _stateManager.MarkSkipped(test, test.Context.SkipReason ?? "Test was skipped"); + + await _eventReceiverOrchestrator.InvokeTestSkippedEventReceiversAsync(test.Context, cancellationToken).ConfigureAwait(false); + + await _eventReceiverOrchestrator.InvokeTestEndEventReceiversAsync(test.Context, cancellationToken).ConfigureAwait(false); + + return false; + } + + _testInitializer.PrepareTest(test, cancellationToken); + + // Initialize data sources outside the timeout scope. + // Clear TestContext.Current so console output during initialization goes to + // GlobalContext (real console) instead of being captured in the test's output buffer. + TestContext.Current = null; + try + { + await _testInitializer.InitializeTestObjectsAsync(test, cancellationToken).ConfigureAwait(false); + } + finally + { + TestContext.Current = test.Context; + } + + test.Context.RestoreExecutionContext(); + + return true; + } + /// /// Core test lifecycle execution: instance creation, initialization, execution, and disposal. - /// Extracted to allow bypassing retry/timeout wrappers when not needed. + /// Used by the fast path (no retry, no timeout) where timeout is not a concern. /// private async ValueTask ExecuteTestLifecycleAsync(AbstractExecutableTest test, CancellationToken cancellationToken) { diff --git a/TUnit.Engine/TestExecutor.cs b/TUnit.Engine/TestExecutor.cs index dcb9cf2bc4..6fb4f42868 100644 --- a/TUnit.Engine/TestExecutor.cs +++ b/TUnit.Engine/TestExecutor.cs @@ -63,7 +63,7 @@ await _beforeHookTaskCache.GetOrCreateBeforeTestSessionTask( /// Creates a test executor delegate that wraps the provided executor with hook orchestration. /// Uses focused services that follow SRP to manage lifecycle and execution. /// - public async ValueTask ExecuteAsync(AbstractExecutableTest executableTest, TestInitializer testInitializer, CancellationToken cancellationToken) + public async ValueTask ExecuteAsync(AbstractExecutableTest executableTest, TestInitializer testInitializer, CancellationToken cancellationToken, bool skipInitialization = false) { var testClass = executableTest.Metadata.TestClassType; @@ -113,9 +113,12 @@ await _eventReceiverOrchestrator.InvokeFirstTestInClassEventReceiversAsync( executableTest.Context.ClassContext.RestoreExecutionContext(); - // Initialize test objects (IAsyncInitializer) AFTER BeforeClass hooks - // This ensures resources like Docker containers are not started until needed - await testInitializer.InitializeTestObjectsAsync(executableTest, cancellationToken).ConfigureAwait(false); + if (!skipInitialization) + { + // Initialize test objects (IAsyncInitializer) AFTER BeforeClass hooks + // This ensures resources like Docker containers are not started until needed + await testInitializer.InitializeTestObjectsAsync(executableTest, cancellationToken).ConfigureAwait(false); + } executableTest.Context.RestoreExecutionContext(); From fd5d86bfa408d21b108bdade3a60f9c60c806bdd Mon Sep 17 00:00:00 2001 From: Tom Longhurst <30480171+thomhurst@users.noreply.github.com> Date: Sat, 14 Feb 2026 12:27:07 +0000 Subject: [PATCH 2/8] fix: remove duplicate DependencyInjectionDataSourceAttribute file AsyncDependencyInjectionDataSourceSourceAttribute.cs was accidentally created as an exact duplicate of DependencyInjectionDataSourceSourceAttribute.cs in commit 1d6ae1fe0, causing CS0101 duplicate definition build errors. Co-Authored-By: Claude Opus 4.6 --- ...dencyInjectionDataSourceSourceAttribute.cs | 44 ------------------- 1 file changed, 44 deletions(-) delete mode 100644 TUnit.Core/Attributes/TestData/AsyncDependencyInjectionDataSourceSourceAttribute.cs diff --git a/TUnit.Core/Attributes/TestData/AsyncDependencyInjectionDataSourceSourceAttribute.cs b/TUnit.Core/Attributes/TestData/AsyncDependencyInjectionDataSourceSourceAttribute.cs deleted file mode 100644 index 3d7ea2468b..0000000000 --- a/TUnit.Core/Attributes/TestData/AsyncDependencyInjectionDataSourceSourceAttribute.cs +++ /dev/null @@ -1,44 +0,0 @@ -using System.Diagnostics.CodeAnalysis; - -namespace TUnit.Core; - -public abstract class DependencyInjectionDataSourceAttribute : UntypedDataSourceGeneratorAttribute -{ - protected override IEnumerable> GenerateDataSources(DataGeneratorMetadata dataGeneratorMetadata) - { - yield return () => - { - // Create a new scope for each test execution - var scope = CreateScope(dataGeneratorMetadata); - - // Set up disposal for this specific scope in the current test context - dataGeneratorMetadata.TestBuilderContext.Current.Events.OnDispose += async (_, _) => - { - if (scope is IAsyncDisposable asyncDisposable) - { - await asyncDisposable.DisposeAsync().ConfigureAwait(false); - } - else if (scope is IDisposable disposable) - { - disposable.Dispose(); - } - }; - - return dataGeneratorMetadata.MembersToGenerate - .Select(m => m switch - { - PropertyMetadata prop => prop.Type, - ParameterMetadata param => param.Type, - ClassMetadata cls => cls.Type, - MethodMetadata method => method.Type, - _ => throw new InvalidOperationException($"Unknown member type: {m.GetType()}") - }) - .Select(x => Create(scope, x)) - .ToArray(); - }; - } - - public abstract TScope CreateScope(DataGeneratorMetadata dataGeneratorMetadata); - - public abstract object? Create(TScope scope, Type type); -} From e1a122750320bf07f22ea7c68cfc65256c73709d Mon Sep 17 00:00:00 2001 From: Tom Longhurst <30480171+thomhurst@users.noreply.github.com> Date: Sat, 14 Feb 2026 12:57:09 +0000 Subject: [PATCH 3/8] fix: use real console writers to prevent infinite recursion in TestOutputSink MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit GlobalContext.OriginalConsoleOut captures Console.Out which is already the OptimizedConsoleInterceptor after initialization. Writing to it from TestOutputSink.Log creates infinite recursion: TestOutputSink.Log → OriginalConsoleOut.WriteLine → Interceptor → RouteToSinks → TestOutputSink.Log → ... Use StandardOutConsoleInterceptor.DefaultOut/DefaultError instead, which are backed by Console.OpenStandardOutput/Error and always bypass the interceptor. Co-Authored-By: Claude Opus 4.6 --- TUnit.Engine/Logging/TestOutputSink.cs | 30 ++++++++++++-------------- 1 file changed, 14 insertions(+), 16 deletions(-) diff --git a/TUnit.Engine/Logging/TestOutputSink.cs b/TUnit.Engine/Logging/TestOutputSink.cs index a2ff518bb2..fa6c32d106 100644 --- a/TUnit.Engine/Logging/TestOutputSink.cs +++ b/TUnit.Engine/Logging/TestOutputSink.cs @@ -19,13 +19,15 @@ public void Log(LogLevel level, string message, Exception? exception, Context? c return; } - // During non-test phases (e.g. data source initialization), write directly to console - // since the output isn't associated with any specific test - if (context is GlobalContext globalContext) + // During non-test phases (e.g. data source initialization), write directly to the + // real console since the output isn't associated with any specific test. + // Use StandardOut/ErrorConsoleInterceptor.DefaultOut/DefaultError (backed by + // Console.OpenStandardOutput/Error) to avoid recursion through the interceptor. + if (context is GlobalContext) { var consoleWriter = level >= LogLevel.Error - ? globalContext.OriginalConsoleError - : globalContext.OriginalConsoleOut; + ? StandardErrorConsoleInterceptor.DefaultError + : StandardOutConsoleInterceptor.DefaultOut; consoleWriter.WriteLine(message); return; } @@ -41,23 +43,19 @@ public ValueTask LogAsync(LogLevel level, string message, Exception? exception, return ValueTask.CompletedTask; } - // During non-test phases (e.g. data source initialization), write directly to console - // since the output isn't associated with any specific test - if (context is GlobalContext globalContext) + // During non-test phases (e.g. data source initialization), write directly to the + // real console since the output isn't associated with any specific test. + if (context is GlobalContext) { var consoleWriter = level >= LogLevel.Error - ? globalContext.OriginalConsoleError - : globalContext.OriginalConsoleOut; - return WriteLineAsync(consoleWriter, message); + ? StandardErrorConsoleInterceptor.DefaultError + : StandardOutConsoleInterceptor.DefaultOut; + consoleWriter.WriteLine(message); + return ValueTask.CompletedTask; } var writer = level >= LogLevel.Error ? context.ErrorOutputWriter : context.OutputWriter; writer.WriteLine(message); return ValueTask.CompletedTask; } - - private static async ValueTask WriteLineAsync(TextWriter writer, string message) - { - await writer.WriteLineAsync(message).ConfigureAwait(false); - } } From cd9ab77f715fcdb111917ec1b9e18d2f4fff6c5c Mon Sep 17 00:00:00 2001 From: Tom Longhurst <30480171+thomhurst@users.noreply.github.com> Date: Sat, 14 Feb 2026 13:03:17 +0000 Subject: [PATCH 4/8] fix: route non-TestContext output to real console in TestOutputSink MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The previous GlobalContext check was insufficient because Context.Current resolves through a chain of async-local contexts (TestSessionContext, AssemblyHookContext, etc.) before reaching GlobalContext. When TestContext.Current is null, Context.Current typically resolves to TestSessionContext rather than GlobalContext, causing the check to fail and output to silently disappear into an unread StringBuilder. Changed to check `context is not TestContext` instead — TestOutputSink's purpose is capturing output for test results, which only applies to TestContext. All other contexts (GlobalContext, TestSessionContext, AssemblyHookContext, etc.) route to the real console via the pre-interception writers (Console.OpenStandardOutput/Error). Co-Authored-By: Claude Opus 4.6 --- TUnit.Engine/Logging/TestOutputSink.cs | 45 +++++++++---------- .../Services/TestExecution/TestCoordinator.cs | 5 ++- 2 files changed, 24 insertions(+), 26 deletions(-) diff --git a/TUnit.Engine/Logging/TestOutputSink.cs b/TUnit.Engine/Logging/TestOutputSink.cs index fa6c32d106..15df94f31b 100644 --- a/TUnit.Engine/Logging/TestOutputSink.cs +++ b/TUnit.Engine/Logging/TestOutputSink.cs @@ -14,21 +14,21 @@ internal sealed class TestOutputSink : ILogSink public void Log(LogLevel level, string message, Exception? exception, Context? context) { - if (context == null) + if (context is not TestContext) { - return; - } + // Only capture output for test contexts (included in test results). + // For non-test contexts (e.g. data source initialization, hooks, GlobalContext), + // write directly to the real console via the pre-interception writers + // to avoid recursion through the console interceptor and to ensure + // the output is visible rather than captured in an unread buffer. + if (context is not null) + { + var consoleWriter = level >= LogLevel.Error + ? StandardErrorConsoleInterceptor.DefaultError + : StandardOutConsoleInterceptor.DefaultOut; + consoleWriter.WriteLine(message); + } - // During non-test phases (e.g. data source initialization), write directly to the - // real console since the output isn't associated with any specific test. - // Use StandardOut/ErrorConsoleInterceptor.DefaultOut/DefaultError (backed by - // Console.OpenStandardOutput/Error) to avoid recursion through the interceptor. - if (context is GlobalContext) - { - var consoleWriter = level >= LogLevel.Error - ? StandardErrorConsoleInterceptor.DefaultError - : StandardOutConsoleInterceptor.DefaultOut; - consoleWriter.WriteLine(message); return; } @@ -38,19 +38,16 @@ public void Log(LogLevel level, string message, Exception? exception, Context? c public ValueTask LogAsync(LogLevel level, string message, Exception? exception, Context? context) { - if (context == null) + if (context is not TestContext) { - return ValueTask.CompletedTask; - } + if (context is not null) + { + var consoleWriter = level >= LogLevel.Error + ? StandardErrorConsoleInterceptor.DefaultError + : StandardOutConsoleInterceptor.DefaultOut; + consoleWriter.WriteLine(message); + } - // During non-test phases (e.g. data source initialization), write directly to the - // real console since the output isn't associated with any specific test. - if (context is GlobalContext) - { - var consoleWriter = level >= LogLevel.Error - ? StandardErrorConsoleInterceptor.DefaultError - : StandardOutConsoleInterceptor.DefaultOut; - consoleWriter.WriteLine(message); return ValueTask.CompletedTask; } diff --git a/TUnit.Engine/Services/TestExecution/TestCoordinator.cs b/TUnit.Engine/Services/TestExecution/TestCoordinator.cs index 507a87490c..e008dd3723 100644 --- a/TUnit.Engine/Services/TestExecution/TestCoordinator.cs +++ b/TUnit.Engine/Services/TestExecution/TestCoordinator.cs @@ -328,8 +328,9 @@ private async ValueTask PrepareAndInitializeOutsideTimeoutAsync(AbstractEx _testInitializer.PrepareTest(test, cancellationToken); // Initialize data sources outside the timeout scope. - // Clear TestContext.Current so console output during initialization goes to - // GlobalContext (real console) instead of being captured in the test's output buffer. + // Clear TestContext.Current so console output during initialization is not + // captured in the test's output buffer. TestOutputSink routes non-TestContext + // output to the real console. TestContext.Current = null; try { From 750eba6cf0f2163120bb59d3ba5eab9e71337316 Mon Sep 17 00:00:00 2001 From: Tom Longhurst <30480171+thomhurst@users.noreply.github.com> Date: Sat, 14 Feb 2026 13:16:37 +0000 Subject: [PATCH 5/8] fix: always show non-test output on console without duplication Split console output responsibility between sinks: - TestOutputSink: only captures TestContext output for test results, no-ops for all other contexts - ConsoleOutputSink: always registered (not just --output Detailed). In detailed mode writes all output; in non-detailed mode only writes non-TestContext output (hooks, data source initialization, etc.) This ensures infrastructure output (data source initialization, hooks) is always visible on the real console regardless of output mode, while test output only appears on console with --output Detailed. No duplication occurs because each sink has a clear, non-overlapping responsibility for non-test contexts. Co-Authored-By: Claude Opus 4.6 --- .../Framework/TUnitServiceProvider.cs | 13 +++++------ TUnit.Engine/Logging/ConsoleOutputSink.cs | 13 +++++++++-- TUnit.Engine/Logging/TestOutputSink.cs | 23 ++----------------- 3 files changed, 19 insertions(+), 30 deletions(-) diff --git a/TUnit.Engine/Framework/TUnitServiceProvider.cs b/TUnit.Engine/Framework/TUnitServiceProvider.cs index d6b6d1f3fa..f75f208c9e 100644 --- a/TUnit.Engine/Framework/TUnitServiceProvider.cs +++ b/TUnit.Engine/Framework/TUnitServiceProvider.cs @@ -144,13 +144,12 @@ public TUnitServiceProvider(IExtension extension, // TestOutputSink: Always registered - accumulates to Context.OutputWriter/ErrorOutputWriter for test results TUnitLoggerFactory.AddSink(new TestOutputSink()); - // ConsoleOutputSink: For --output Detailed mode - real-time console output - if (VerbosityService.IsDetailedOutput) - { - TUnitLoggerFactory.AddSink(new ConsoleOutputSink( - StandardOutConsoleInterceptor.DefaultOut, - StandardErrorConsoleInterceptor.DefaultError)); - } + // ConsoleOutputSink: Always registered - writes non-test output (hooks, data source + // initialization) to the real console. In --output Detailed mode, also writes test output. + TUnitLoggerFactory.AddSink(new ConsoleOutputSink( + StandardOutConsoleInterceptor.DefaultOut, + StandardErrorConsoleInterceptor.DefaultError, + VerbosityService.IsDetailedOutput)); // IdeStreamingSink: For IDE clients - real-time output streaming // Disabled by default due to compatibility issues with Microsoft Testing Platform diff --git a/TUnit.Engine/Logging/ConsoleOutputSink.cs b/TUnit.Engine/Logging/ConsoleOutputSink.cs index ed05254333..ac6a285a86 100644 --- a/TUnit.Engine/Logging/ConsoleOutputSink.cs +++ b/TUnit.Engine/Logging/ConsoleOutputSink.cs @@ -5,23 +5,32 @@ namespace TUnit.Engine.Logging; /// /// A log sink that writes output to the actual console (stdout/stderr). -/// Only registered when --output Detailed is specified. +/// Always registered. In detailed mode, writes all output. In non-detailed mode, +/// only writes non-test output (hooks, data source initialization, etc.) so that +/// infrastructure output is always visible on the console. /// internal sealed class ConsoleOutputSink : ILogSink { private readonly TextWriter _stdout; private readonly TextWriter _stderr; + private readonly bool _detailedOutput; - public ConsoleOutputSink(TextWriter stdout, TextWriter stderr) + public ConsoleOutputSink(TextWriter stdout, TextWriter stderr, bool detailedOutput) { _stdout = stdout; _stderr = stderr; + _detailedOutput = detailedOutput; } public bool IsEnabled(LogLevel level) => true; public void Log(LogLevel level, string message, Exception? exception, Context? context) { + if (!_detailedOutput && context is TestContext) + { + return; + } + var writer = level >= LogLevel.Error ? _stderr : _stdout; writer.WriteLine(message); } diff --git a/TUnit.Engine/Logging/TestOutputSink.cs b/TUnit.Engine/Logging/TestOutputSink.cs index 15df94f31b..c51d254880 100644 --- a/TUnit.Engine/Logging/TestOutputSink.cs +++ b/TUnit.Engine/Logging/TestOutputSink.cs @@ -7,6 +7,8 @@ namespace TUnit.Engine.Logging; /// A log sink that accumulates output to the test context's output writers. /// Routes to OutputWriter for non-error levels and ErrorOutputWriter for error levels. /// This captured output is included in test results. +/// Only captures output for TestContext — non-test contexts (hooks, data source +/// initialization, GlobalContext) are handled by ConsoleOutputSink when registered. /// internal sealed class TestOutputSink : ILogSink { @@ -16,19 +18,6 @@ public void Log(LogLevel level, string message, Exception? exception, Context? c { if (context is not TestContext) { - // Only capture output for test contexts (included in test results). - // For non-test contexts (e.g. data source initialization, hooks, GlobalContext), - // write directly to the real console via the pre-interception writers - // to avoid recursion through the console interceptor and to ensure - // the output is visible rather than captured in an unread buffer. - if (context is not null) - { - var consoleWriter = level >= LogLevel.Error - ? StandardErrorConsoleInterceptor.DefaultError - : StandardOutConsoleInterceptor.DefaultOut; - consoleWriter.WriteLine(message); - } - return; } @@ -40,14 +29,6 @@ public ValueTask LogAsync(LogLevel level, string message, Exception? exception, { if (context is not TestContext) { - if (context is not null) - { - var consoleWriter = level >= LogLevel.Error - ? StandardErrorConsoleInterceptor.DefaultError - : StandardOutConsoleInterceptor.DefaultOut; - consoleWriter.WriteLine(message); - } - return ValueTask.CompletedTask; } From 913073ac0a4a01e24160fe44f55df4a25953f7fe Mon Sep 17 00:00:00 2001 From: Tom Longhurst <30480171+thomhurst@users.noreply.github.com> Date: Sat, 14 Feb 2026 13:53:23 +0000 Subject: [PATCH 6/8] fix: move timeout inside ExecuteAsync to wrap only test body MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The previous approach extracted initialization into a separate phase (PrepareAndInitializeOutsideTimeoutAsync) which ran initialization BEFORE hooks, breaking the execution order. Tests depending on BeforeClass hooks running before initialization failed. New approach: pass the test timeout into TestExecutor.ExecuteAsync, which applies TimeoutHelper only around ExecuteTestAsync (the test body). Hooks and data source initialization (InitializeTestObjectsAsync) run outside the timeout with the original cancellation token. Also reverts the TestOutputSink/ConsoleOutputSink changes that were causing output capture test failures — during the build phase, Context.Current is a TestBuildContext (not TestContext), so the "context is not TestContext" check prevented output from being captured in test results. Co-Authored-By: Claude Opus 4.6 --- .../Framework/TUnitServiceProvider.cs | 13 +- TUnit.Engine/Logging/ConsoleOutputSink.cs | 13 +- TUnit.Engine/Logging/TestOutputSink.cs | 12 +- .../Services/TestExecution/TestCoordinator.cs | 112 ++---------------- TUnit.Engine/TestExecutor.cs | 29 +++-- 5 files changed, 39 insertions(+), 140 deletions(-) diff --git a/TUnit.Engine/Framework/TUnitServiceProvider.cs b/TUnit.Engine/Framework/TUnitServiceProvider.cs index f75f208c9e..d6b6d1f3fa 100644 --- a/TUnit.Engine/Framework/TUnitServiceProvider.cs +++ b/TUnit.Engine/Framework/TUnitServiceProvider.cs @@ -144,12 +144,13 @@ public TUnitServiceProvider(IExtension extension, // TestOutputSink: Always registered - accumulates to Context.OutputWriter/ErrorOutputWriter for test results TUnitLoggerFactory.AddSink(new TestOutputSink()); - // ConsoleOutputSink: Always registered - writes non-test output (hooks, data source - // initialization) to the real console. In --output Detailed mode, also writes test output. - TUnitLoggerFactory.AddSink(new ConsoleOutputSink( - StandardOutConsoleInterceptor.DefaultOut, - StandardErrorConsoleInterceptor.DefaultError, - VerbosityService.IsDetailedOutput)); + // ConsoleOutputSink: For --output Detailed mode - real-time console output + if (VerbosityService.IsDetailedOutput) + { + TUnitLoggerFactory.AddSink(new ConsoleOutputSink( + StandardOutConsoleInterceptor.DefaultOut, + StandardErrorConsoleInterceptor.DefaultError)); + } // IdeStreamingSink: For IDE clients - real-time output streaming // Disabled by default due to compatibility issues with Microsoft Testing Platform diff --git a/TUnit.Engine/Logging/ConsoleOutputSink.cs b/TUnit.Engine/Logging/ConsoleOutputSink.cs index ac6a285a86..ed05254333 100644 --- a/TUnit.Engine/Logging/ConsoleOutputSink.cs +++ b/TUnit.Engine/Logging/ConsoleOutputSink.cs @@ -5,32 +5,23 @@ namespace TUnit.Engine.Logging; /// /// A log sink that writes output to the actual console (stdout/stderr). -/// Always registered. In detailed mode, writes all output. In non-detailed mode, -/// only writes non-test output (hooks, data source initialization, etc.) so that -/// infrastructure output is always visible on the console. +/// Only registered when --output Detailed is specified. /// internal sealed class ConsoleOutputSink : ILogSink { private readonly TextWriter _stdout; private readonly TextWriter _stderr; - private readonly bool _detailedOutput; - public ConsoleOutputSink(TextWriter stdout, TextWriter stderr, bool detailedOutput) + public ConsoleOutputSink(TextWriter stdout, TextWriter stderr) { _stdout = stdout; _stderr = stderr; - _detailedOutput = detailedOutput; } public bool IsEnabled(LogLevel level) => true; public void Log(LogLevel level, string message, Exception? exception, Context? context) { - if (!_detailedOutput && context is TestContext) - { - return; - } - var writer = level >= LogLevel.Error ? _stderr : _stdout; writer.WriteLine(message); } diff --git a/TUnit.Engine/Logging/TestOutputSink.cs b/TUnit.Engine/Logging/TestOutputSink.cs index c51d254880..7f7426e843 100644 --- a/TUnit.Engine/Logging/TestOutputSink.cs +++ b/TUnit.Engine/Logging/TestOutputSink.cs @@ -7,8 +7,6 @@ namespace TUnit.Engine.Logging; /// A log sink that accumulates output to the test context's output writers. /// Routes to OutputWriter for non-error levels and ErrorOutputWriter for error levels. /// This captured output is included in test results. -/// Only captures output for TestContext — non-test contexts (hooks, data source -/// initialization, GlobalContext) are handled by ConsoleOutputSink when registered. /// internal sealed class TestOutputSink : ILogSink { @@ -16,7 +14,7 @@ internal sealed class TestOutputSink : ILogSink public void Log(LogLevel level, string message, Exception? exception, Context? context) { - if (context is not TestContext) + if (context == null) { return; } @@ -27,13 +25,7 @@ public void Log(LogLevel level, string message, Exception? exception, Context? c public ValueTask LogAsync(LogLevel level, string message, Exception? exception, Context? context) { - if (context is not TestContext) - { - return ValueTask.CompletedTask; - } - - var writer = level >= LogLevel.Error ? context.ErrorOutputWriter : context.OutputWriter; - writer.WriteLine(message); + Log(level, message, exception, context); return ValueTask.CompletedTask; } } diff --git a/TUnit.Engine/Services/TestExecution/TestCoordinator.cs b/TUnit.Engine/Services/TestExecution/TestCoordinator.cs index e008dd3723..84e252c927 100644 --- a/TUnit.Engine/Services/TestExecution/TestCoordinator.cs +++ b/TUnit.Engine/Services/TestExecution/TestCoordinator.cs @@ -112,61 +112,12 @@ private async ValueTask ExecuteTestInternalAsync(AbstractExecutableTest test, Ca } else { - // Slow path: use retry and timeout wrappers - // Data source initialization runs OUTSIDE the timeout so it doesn't - // count against the test's timeout (fixes #4772) + // Slow path: use retry wrapper + // Timeout is handled inside TestExecutor.ExecuteAsync, wrapping only the test body + // (not hooks or data source initialization) — fixes #4772 await RetryHelper.ExecuteWithRetry(test.Context, async () => { - // Phase 1: Instance creation and initialization OUTSIDE timeout - var shouldExecute = await PrepareAndInitializeOutsideTimeoutAsync(test, cancellationToken).ConfigureAwait(false); - - if (!shouldExecute) - { - return; - } - - // Phase 2: Test execution INSIDE timeout - try - { - var timeoutMessage = testTimeout.HasValue - ? $"Test '{test.Context.Metadata.TestDetails.TestName}' timed out after {testTimeout.Value}" - : null; - - await TimeoutHelper.ExecuteWithTimeoutAsync( - ct => _testExecutor.ExecuteAsync(test, _testInitializer, ct, skipInitialization: true).AsTask(), - testTimeout, - cancellationToken, - timeoutMessage).ConfigureAwait(false); - } - finally - { - // Dispose test instance and fire OnDispose after each attempt - // This ensures each retry gets a fresh instance - var onDispose = test.Context.InternalEvents.OnDispose; - if (onDispose?.InvocationList != null) - { - foreach (var invocation in onDispose.InvocationList) - { - try - { - await invocation.InvokeAsync(test.Context, test.Context).ConfigureAwait(false); - } - catch (Exception disposeEx) - { - await _logger.LogErrorAsync($"Error during OnDispose for {test.TestId}: {disposeEx}").ConfigureAwait(false); - } - } - } - - try - { - await TestExecutor.DisposeTestInstance(test).ConfigureAwait(false); - } - catch (Exception disposeEx) - { - await _logger.LogErrorAsync($"Error disposing test instance for {test.TestId}: {disposeEx}").ConfigureAwait(false); - } - } + await ExecuteTestLifecycleAsync(test, cancellationToken).ConfigureAwait(false); }).ConfigureAwait(false); } @@ -297,58 +248,10 @@ await _eventReceiverOrchestrator.InvokeLastTestInSessionEventReceiversAsync( } } - /// - /// Phase 1 of the slow path: creates the test instance, checks for skip, prepares and - /// initializes data sources. Runs OUTSIDE the timeout wrapper so data source initialization - /// does not count against the test's timeout (fixes #4772). - /// Console output during initialization goes to GlobalContext (real console) instead of - /// being captured in the test's output buffer. - /// - /// true if the test should proceed to execution; false if it was skipped. - private async ValueTask PrepareAndInitializeOutsideTimeoutAsync(AbstractExecutableTest test, CancellationToken cancellationToken) - { - test.Context.Metadata.TestDetails.ClassInstance = await test.CreateInstanceAsync().ConfigureAwait(false); - - // Invalidate cached eligible event objects since ClassInstance changed - test.Context.CachedEligibleEventObjects = null; - - // Check if this test should be skipped (after creating instance) - if (test.Context.Metadata.TestDetails.ClassInstance is SkippedTestInstance || - !string.IsNullOrEmpty(test.Context.SkipReason)) - { - _stateManager.MarkSkipped(test, test.Context.SkipReason ?? "Test was skipped"); - - await _eventReceiverOrchestrator.InvokeTestSkippedEventReceiversAsync(test.Context, cancellationToken).ConfigureAwait(false); - - await _eventReceiverOrchestrator.InvokeTestEndEventReceiversAsync(test.Context, cancellationToken).ConfigureAwait(false); - - return false; - } - - _testInitializer.PrepareTest(test, cancellationToken); - - // Initialize data sources outside the timeout scope. - // Clear TestContext.Current so console output during initialization is not - // captured in the test's output buffer. TestOutputSink routes non-TestContext - // output to the real console. - TestContext.Current = null; - try - { - await _testInitializer.InitializeTestObjectsAsync(test, cancellationToken).ConfigureAwait(false); - } - finally - { - TestContext.Current = test.Context; - } - - test.Context.RestoreExecutionContext(); - - return true; - } - /// /// Core test lifecycle execution: instance creation, initialization, execution, and disposal. - /// Used by the fast path (no retry, no timeout) where timeout is not a concern. + /// Timeout is passed through to TestExecutor.ExecuteAsync, which applies it only to the test + /// body — hooks and data source initialization run outside the timeout scope (fixes #4772). /// private async ValueTask ExecuteTestLifecycleAsync(AbstractExecutableTest test, CancellationToken cancellationToken) { @@ -391,7 +294,8 @@ private async ValueTask ExecuteTestLifecycleAsync(AbstractExecutableTest test, C { _testInitializer.PrepareTest(test, cancellationToken); test.Context.RestoreExecutionContext(); - await _testExecutor.ExecuteAsync(test, _testInitializer, cancellationToken).ConfigureAwait(false); + var testTimeout = test.Context.Metadata.TestDetails.Timeout; + await _testExecutor.ExecuteAsync(test, _testInitializer, cancellationToken, testTimeout).ConfigureAwait(false); } finally { diff --git a/TUnit.Engine/TestExecutor.cs b/TUnit.Engine/TestExecutor.cs index 6fb4f42868..fe38fc5c46 100644 --- a/TUnit.Engine/TestExecutor.cs +++ b/TUnit.Engine/TestExecutor.cs @@ -63,7 +63,7 @@ await _beforeHookTaskCache.GetOrCreateBeforeTestSessionTask( /// Creates a test executor delegate that wraps the provided executor with hook orchestration. /// Uses focused services that follow SRP to manage lifecycle and execution. /// - public async ValueTask ExecuteAsync(AbstractExecutableTest executableTest, TestInitializer testInitializer, CancellationToken cancellationToken, bool skipInitialization = false) + public async ValueTask ExecuteAsync(AbstractExecutableTest executableTest, TestInitializer testInitializer, CancellationToken cancellationToken, TimeSpan? testTimeout = null) { var testClass = executableTest.Metadata.TestClassType; @@ -113,12 +113,9 @@ await _eventReceiverOrchestrator.InvokeFirstTestInClassEventReceiversAsync( executableTest.Context.ClassContext.RestoreExecutionContext(); - if (!skipInitialization) - { - // Initialize test objects (IAsyncInitializer) AFTER BeforeClass hooks - // This ensures resources like Docker containers are not started until needed - await testInitializer.InitializeTestObjectsAsync(executableTest, cancellationToken).ConfigureAwait(false); - } + // Initialize test objects (IAsyncInitializer) AFTER BeforeClass hooks + // This ensures resources like Docker containers are not started until needed + await testInitializer.InitializeTestObjectsAsync(executableTest, cancellationToken).ConfigureAwait(false); executableTest.Context.RestoreExecutionContext(); @@ -135,10 +132,24 @@ await Timings.Record("BeforeTest", executableTest.Context, executableTest.Context.RestoreExecutionContext(); - // Timeout is now enforced at TestCoordinator level (wrapping entire lifecycle) + // Only the test body is subject to the [Timeout] — hooks and data source + // initialization run outside the timeout scope (fixes #4772) try { - await ExecuteTestAsync(executableTest, cancellationToken).ConfigureAwait(false); + if (testTimeout.HasValue) + { + var timeoutMessage = $"Test '{executableTest.Context.Metadata.TestDetails.TestName}' timed out after {testTimeout.Value}"; + + await TimeoutHelper.ExecuteWithTimeoutAsync( + ct => ExecuteTestAsync(executableTest, ct).AsTask(), + testTimeout, + cancellationToken, + timeoutMessage).ConfigureAwait(false); + } + else + { + await ExecuteTestAsync(executableTest, cancellationToken).ConfigureAwait(false); + } } finally { From 28e03f405e4da05d0d8a010699219c6dc6c72c28 Mon Sep 17 00:00:00 2001 From: Tom Longhurst <30480171+thomhurst@users.noreply.github.com> Date: Sat, 14 Feb 2026 13:57:32 +0000 Subject: [PATCH 7/8] chore: downgrade per-test grouping logs from debug to trace MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The per-test categorization messages (e.g. "→ Parallel (no constraints)") are emitted for every test and clutter debug output. Move them to trace level. The aggregate summary block stays at debug. Co-Authored-By: Claude Opus 4.6 --- TUnit.Engine/Services/TestGroupingService.cs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/TUnit.Engine/Services/TestGroupingService.cs b/TUnit.Engine/Services/TestGroupingService.cs index 21eb1c045a..7dead59b89 100644 --- a/TUnit.Engine/Services/TestGroupingService.cs +++ b/TUnit.Engine/Services/TestGroupingService.cs @@ -97,26 +97,26 @@ public async ValueTask GroupTestsByConstraintsAsync(IEnumerable 0 ? $" (keys: {string.Join(", ", notInParallel.NotInParallelConstraintKeys)})" : ""; - await _logger.LogDebugAsync($"Test '{test.TestId}': → NotInParallel{keys}{parallelLimiterInfo}").ConfigureAwait(false); + await _logger.LogTraceAsync($"Test '{test.TestId}': → NotInParallel{keys}{parallelLimiterInfo}").ConfigureAwait(false); ProcessNotInParallelConstraint(test, sortKey.ClassFullName, notInParallel, notInParallelList, keyedNotInParallelList); } else { // No constraints - can run in parallel - await _logger.LogDebugAsync($"Test '{test.TestId}': → Parallel (no constraints){parallelLimiterInfo}").ConfigureAwait(false); + await _logger.LogTraceAsync($"Test '{test.TestId}': → Parallel (no constraints){parallelLimiterInfo}").ConfigureAwait(false); parallelTests.Add(test); } } From 84418c7392a2847b0c8712228c6f55366bb9727a Mon Sep 17 00:00:00 2001 From: Tom Longhurst <30480171+thomhurst@users.noreply.github.com> Date: Sat, 14 Feb 2026 14:08:56 +0000 Subject: [PATCH 8/8] perf: add ValueTask overload to TimeoutHelper Avoids .AsTask() allocation on the no-timeout fast path by returning the ValueTask directly. The timeout path converts to Task internally since WhenAny requires it. Simplifies the TestExecutor call site. Co-Authored-By: Claude Opus 4.6 --- TUnit.Engine/Helpers/TimeoutHelper.cs | 37 +++++++++++++++++++++++++++ TUnit.Engine/TestExecutor.cs | 23 +++++++---------- 2 files changed, 46 insertions(+), 14 deletions(-) diff --git a/TUnit.Engine/Helpers/TimeoutHelper.cs b/TUnit.Engine/Helpers/TimeoutHelper.cs index 13d8b06057..2e21204d9f 100644 --- a/TUnit.Engine/Helpers/TimeoutHelper.cs +++ b/TUnit.Engine/Helpers/TimeoutHelper.cs @@ -10,6 +10,43 @@ internal static class TimeoutHelper /// private static readonly TimeSpan GracePeriod = TimeSpan.FromSeconds(1); + /// + /// Executes a ValueTask-returning operation with an optional timeout. + /// On the fast path (no timeout), returns the ValueTask directly without Task allocation. + /// + public static ValueTask ExecuteWithTimeoutAsync( + Func valueTaskFactory, + TimeSpan? timeout, + CancellationToken cancellationToken, + string? timeoutMessage = null) + { + // Fast path: no timeout - return ValueTask directly (zero allocation, no state machine) + if (!timeout.HasValue) + { + return valueTaskFactory(cancellationToken); + } + + // Timeout path: convert to Task for WhenAny support + return new ValueTask(ExecuteWithTimeoutCoreAsync(valueTaskFactory, timeout.Value, cancellationToken, timeoutMessage)); + } + + private static async Task ExecuteWithTimeoutCoreAsync( + Func valueTaskFactory, + TimeSpan timeout, + CancellationToken cancellationToken, + string? timeoutMessage) + { + await ExecuteWithTimeoutAsync( + async ct => + { + await valueTaskFactory(ct).ConfigureAwait(false); + return true; + }, + timeout, + cancellationToken, + timeoutMessage).ConfigureAwait(false); + } + /// /// Executes a task with an optional timeout. If the timeout elapses before the task completes, /// control is returned to the caller immediately with a TimeoutException. diff --git a/TUnit.Engine/TestExecutor.cs b/TUnit.Engine/TestExecutor.cs index fe38fc5c46..425160c71d 100644 --- a/TUnit.Engine/TestExecutor.cs +++ b/TUnit.Engine/TestExecutor.cs @@ -136,20 +136,15 @@ await Timings.Record("BeforeTest", executableTest.Context, // initialization run outside the timeout scope (fixes #4772) try { - if (testTimeout.HasValue) - { - var timeoutMessage = $"Test '{executableTest.Context.Metadata.TestDetails.TestName}' timed out after {testTimeout.Value}"; - - await TimeoutHelper.ExecuteWithTimeoutAsync( - ct => ExecuteTestAsync(executableTest, ct).AsTask(), - testTimeout, - cancellationToken, - timeoutMessage).ConfigureAwait(false); - } - else - { - await ExecuteTestAsync(executableTest, cancellationToken).ConfigureAwait(false); - } + var timeoutMessage = testTimeout.HasValue + ? $"Test '{executableTest.Context.Metadata.TestDetails.TestName}' timed out after {testTimeout.Value}" + : null; + + await TimeoutHelper.ExecuteWithTimeoutAsync( + ct => ExecuteTestAsync(executableTest, ct), + testTimeout, + cancellationToken, + timeoutMessage).ConfigureAwait(false); } finally {