diff --git a/src/bunit/Extensions/WaitForHelpers/WaitForElementsHelper.cs b/src/bunit/Extensions/WaitForHelpers/WaitForElementsHelper.cs index ec50c9fd4..eb30611b5 100644 --- a/src/bunit/Extensions/WaitForHelpers/WaitForElementsHelper.cs +++ b/src/bunit/Extensions/WaitForHelpers/WaitForElementsHelper.cs @@ -16,16 +16,27 @@ public WaitForElementsHelper(IRenderedComponent renderedComponent, s } } +// Primary constructor, so matchElementCount is captured before the base constructor starts the timeout timer, +// which reads TimeoutErrorMessage and may fire before a regular constructor body would have assigned the field. /// /// Represents an async wait helper, that will wait for a specified time for element(s) of type to become available in the DOM. /// -internal class WaitForElementsHelper : WaitForHelper, TComponent> +internal class WaitForElementsHelper(IRenderedComponent renderedComponent, string cssSelector, int? matchElementCount, TimeSpan? timeout = null) + : WaitForHelper, TComponent>(renderedComponent, () => + { + var elements = renderedComponent.FindAll(cssSelector); + + var checkPassed = matchElementCount is null + ? elements.Count > 0 + : elements.Count == matchElementCount; + + return (checkPassed, elements); + }, timeout) where TComponent : IComponent where TElement : class, IElement { internal const string TimeoutBeforeFoundMessage = "The CSS selector did not result in any matching element(s) before the timeout period passed."; internal static readonly CompositeFormat TimeoutBeforeFoundWithCountMessage = CompositeFormat.Parse("The CSS selector did not result in exactly {0} matching element(s) before the timeout period passed."); - private readonly int? matchElementCount; /// protected override string? TimeoutErrorMessage => matchElementCount is null @@ -34,19 +45,4 @@ internal class WaitForElementsHelper : WaitForHelper protected override bool StopWaitingOnCheckException => true; - - public WaitForElementsHelper(IRenderedComponent renderedComponent, string cssSelector, int? matchElementCount, TimeSpan? timeout = null) - : base(renderedComponent, () => - { - var elements = renderedComponent.FindAll(cssSelector); - - var checkPassed = matchElementCount is null - ? elements.Count > 0 - : elements.Count == matchElementCount; - - return (checkPassed, elements); - }, timeout) - { - this.matchElementCount = matchElementCount; - } } diff --git a/src/bunit/Extensions/WaitForHelpers/WaitForHelper.cs b/src/bunit/Extensions/WaitForHelpers/WaitForHelper.cs index d8e5111e1..1a5736325 100644 --- a/src/bunit/Extensions/WaitForHelpers/WaitForHelper.cs +++ b/src/bunit/Extensions/WaitForHelpers/WaitForHelper.cs @@ -16,7 +16,8 @@ internal abstract class WaitForHelper : IDisposable private readonly IRenderedComponent renderedComponent; private readonly ILogger> logger; private readonly BunitRenderer renderer; - private readonly Timer? timer; + private readonly TimeSpan runtimeTimeout; + private Timer? timer; private bool isDisposed; private bool isChecking; private bool isDirty; @@ -82,37 +83,14 @@ protected WaitForHelper( .Renderer; checkPassedCompletionSource = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); - // Create the wait task and run the initial check - // and subscribe to the OnAfterRender event. - // This must happen before the timer is started, - // as the check happens inside the renderers synchronization context, - // and that may be blocked longer than the timeout on overloaded systems, - // resulting in the timer completing before a single check has - // has a chance to complete. + runtimeTimeout = GetRuntimeTimeout(timeout); + + // Create the wait task, run the initial check and subscribe to the OnAfterRender event. + // The timer is only started after the initial check ran on the renderers synchronization context, + // as that may be blocked longer than the timeout on overloaded systems, + // resulting in the timer completing before a single check has had a chance to run. WaitTask = CreateWaitTask(); CheckAndInitializeWaiting(); - - // If the initial check did not complete successfully, - // start the timer and recheck after every render until the timer expires. - if (!WaitTask.IsCompleted) - { - timer = new Timer( - static (state) => - { - var @this = (WaitForHelper)state!; - @this.logger.LogWaiterTimedOut(@this.renderedComponent.ComponentId); - @this.checkPassedCompletionSource.TrySetException( - new WaitForFailedException( - @this.TimeoutErrorMessage ?? string.Empty, - @this.checkCount, - @this.renderedComponent.RenderCount, - @this.renderer.RenderCount, - @this.capturedException)); - }, - this, - GetRuntimeTimeout(timeout), - Timeout.InfiniteTimeSpan); - } } /// @@ -138,8 +116,12 @@ protected virtual void Dispose(bool disposing) if (isDisposed || !disposing) return; - isDisposed = true; - timer?.Dispose(); + lock (checkPassedCompletionSource) + { + isDisposed = true; + timer?.Dispose(); + } + checkPassedCompletionSource.TrySetCanceled(); renderedComponent.OnAfterRender -= OnAfterRender; logger.LogWaiterDisposed(renderedComponent.ComponentId); @@ -159,12 +141,50 @@ private void CheckAndInitializeWaiting() { // Before subscribing to renderedFragment.OnAfterRender, // we need to make sure that the desired state has not already been reached. - OnAfterRender(this, EventArgs.Empty); - SubscribeToOnAfterRender(); + // The returned task is discarded, so failures, e.g. an invalid timeout, must be forwarded to the WaitTask, + // otherwise the waiter would hang without a timer. + try + { + OnAfterRender(this, EventArgs.Empty); + SubscribeToOnAfterRender(); + StartTimer(); + } + catch (Exception ex) + { + checkPassedCompletionSource.TrySetException(ex); + Dispose(); + } }); } } + private void StartTimer() + { + lock (checkPassedCompletionSource) + { + if (isDisposed || WaitTask.IsCompleted) + return; + + var started = Stopwatch.StartNew(); + timer = new Timer( + static (state) => + { + var (@this, started) = ((WaitForHelper, Stopwatch))state!; + @this.logger.LogWaiterTimedOut(@this.renderedComponent.ComponentId, @this.runtimeTimeout.TotalMilliseconds, started.ElapsedMilliseconds, ThreadPool.ThreadCount, ThreadPool.PendingWorkItemCount); + @this.checkPassedCompletionSource.TrySetException( + new WaitForFailedException( + @this.TimeoutErrorMessage ?? string.Empty, + @this.checkCount, + @this.renderedComponent.RenderCount, + @this.renderer.RenderCount, + @this.capturedException)); + }, + (this, started), + runtimeTimeout, + Timeout.InfiniteTimeSpan); + } + } + private Task CreateWaitTask() { // Two to failure conditions, that the renderer captures an unhandled diff --git a/src/bunit/Extensions/WaitForHelpers/WaitForHelperLoggerExtensions.cs b/src/bunit/Extensions/WaitForHelpers/WaitForHelperLoggerExtensions.cs index bd15e2f25..c771746f4 100644 --- a/src/bunit/Extensions/WaitForHelpers/WaitForHelperLoggerExtensions.cs +++ b/src/bunit/Extensions/WaitForHelpers/WaitForHelperLoggerExtensions.cs @@ -37,8 +37,8 @@ internal static partial class WaitForHelperLoggerExtensions EventId = 10, EventName = "WaiterTimedOut", Level = LogLevel.Debug, - Message = "The waiter for component {ComponentId} timed out.")] - internal static partial void LogWaiterTimedOut(this ILogger logger, int componentId); + Message = "The waiter for component {ComponentId} timed out. Configured: {ConfiguredMs}ms, actual: {ElapsedMs}ms, pool threads: {PoolThreads}, pending pool items: {PendingItems}.")] + internal static partial void LogWaiterTimedOut(this ILogger logger, int componentId, double configuredMs, long elapsedMs, int poolThreads, long pendingItems); [LoggerMessage( EventId = 20, diff --git a/tests/bunit.tests/Assembly.cs b/tests/bunit.tests/Assembly.cs index 786c37ff8..7ea1fae08 100644 --- a/tests/bunit.tests/Assembly.cs +++ b/tests/bunit.tests/Assembly.cs @@ -1 +1,17 @@ +using System.Runtime.CompilerServices; + [assembly: System.Diagnostics.CodeAnalysis.ExcludeFromCodeCoverage] + +namespace Bunit; + +internal static class ThreadPoolSetup +{ + // Many tests block a pool thread synchronously (WaitFor*, Click) while xunit runs 2x processor count in parallel, + // so the default pool floor starves the continuations those tests wait on, causing sporadic WaitFor* timeouts on CI. + [ModuleInitializer] + internal static void RaiseMinThreads() + { + ThreadPool.GetMinThreads(out var workers, out var io); + ThreadPool.SetMinThreads(Math.Max(workers, Environment.ProcessorCount * 4), io); + } +} diff --git a/tests/bunit.tests/Extensions/WaitForHelpers/RenderedComponentWaitForHelperExtensions.cs b/tests/bunit.tests/Extensions/WaitForHelpers/RenderedComponentWaitForHelperExtensions.cs index 0d0044ea4..eb6f61e1c 100644 --- a/tests/bunit.tests/Extensions/WaitForHelpers/RenderedComponentWaitForHelperExtensions.cs +++ b/tests/bunit.tests/Extensions/WaitForHelpers/RenderedComponentWaitForHelperExtensions.cs @@ -240,6 +240,45 @@ await cut.WaitForAssertionAsync(async () => expected.Message.ShouldStartWith(WaitForAssertionHelper.TimeoutMessage); } + [Fact(DisplayName = "WaitForElementAsync runs the initial check before the timeout starts when the dispatcher is busy")] + public async Task Test500() + { + var cut = Render(); + var cancellationToken = Xunit.TestContext.Current.CancellationToken; + using var dispatcherEntered = new ManualResetEventSlim(); + using var releaseDispatcher = new ManualResetEventSlim(); + var blocker = Task.Run(() => cut.InvokeAsync(() => + { + dispatcherEntered.Set(); + releaseDispatcher.Wait(); + }), cancellationToken); + + Task waitTask; + try + { + dispatcherEntered.Wait(cancellationToken); + waitTask = cut.WaitForElementAsync("#notHere", TimeSpan.FromMilliseconds(5)); + await Task.Delay(50, cancellationToken); + } + finally + { + releaseDispatcher.Set(); + await blocker; + } + + var expected = await Should.ThrowAsync(waitTask); + expected.InnerException.ShouldBeOfType(); + } + + [Fact(DisplayName = "WaitForStateAsync throws instead of hanging when the timeout is invalid")] + public async Task Test501() + { + var cut = Render(); + + await Should.ThrowAsync( + cut.WaitForStateAsync(() => false, TimeSpan.FromMilliseconds(-2)).WaitAsync(TimeSpan.FromSeconds(5), Xunit.TestContext.Current.CancellationToken)); + } + private sealed class ThrowsAfterAsyncOperation : ComponentBase { protected override async Task OnInitializedAsync()