diff --git a/src/bunit.core/Extensions/WaitForHelpers/WaitForHelperLoggerExtensions.cs b/src/bunit.core/Extensions/WaitForHelpers/WaitForHelperLoggerExtensions.cs index 53e35419b..f338ad64b 100644 --- a/src/bunit.core/Extensions/WaitForHelpers/WaitForHelperLoggerExtensions.cs +++ b/src/bunit.core/Extensions/WaitForHelpers/WaitForHelperLoggerExtensions.cs @@ -5,22 +5,22 @@ namespace Bunit.Extensions.WaitForHelpers; internal static class WaitForHelperLoggerExtensions { private static readonly Action CheckingWaitCondition - = LoggerMessage.Define(LogLevel.Debug, new EventId(1, "OnAfterRender"), "Checking the wait condition for component {Id}."); + = LoggerMessage.Define(LogLevel.Debug, new EventId(1, "CheckingWaitCondition"), "Checking the wait condition for component {Id}."); private static readonly Action CheckCompleted - = LoggerMessage.Define(LogLevel.Debug, new EventId(2, "OnAfterRender"), "The check completed successfully for component {Id}."); + = LoggerMessage.Define(LogLevel.Debug, new EventId(2, "CheckCompleted"), "The check completed successfully for component {Id}."); private static readonly Action CheckFailed - = LoggerMessage.Define(LogLevel.Debug, new EventId(3, "OnAfterRender"), "The check failed for component {Id}."); + = LoggerMessage.Define(LogLevel.Debug, new EventId(3, "CheckFailed"), "The check failed for component {Id}."); private static readonly Action CheckThrow - = LoggerMessage.Define(LogLevel.Debug, new EventId(4, "OnAfterRender"), "The checker for component {Id} throw an exception."); + = LoggerMessage.Define(LogLevel.Debug, new EventId(4, "CheckThrow"), "The checker for component {Id} throw an exception."); private static readonly Action WaiterTimedOut - = LoggerMessage.Define(LogLevel.Debug, new EventId(10, "OnTimeout"), "The waiter for component {Id} timed out."); + = LoggerMessage.Define(LogLevel.Debug, new EventId(10, "WaiterTimedOut"), "The waiter for component {Id} timed out."); private static readonly Action WaiterDisposed - = LoggerMessage.Define(LogLevel.Debug, new EventId(20, "OnTimeout"), "The waiter for component {Id} disposed."); + = LoggerMessage.Define(LogLevel.Debug, new EventId(20, "WaiterDisposed"), "The waiter for component {Id} disposed."); internal static void LogCheckingWaitCondition(this ILogger> logger, int componentId) { diff --git a/src/bunit.core/Rendering/RenderEvent.cs b/src/bunit.core/Rendering/RenderEvent.cs index ee717037c..09246b29d 100644 --- a/src/bunit.core/Rendering/RenderEvent.cs +++ b/src/bunit.core/Rendering/RenderEvent.cs @@ -5,24 +5,15 @@ namespace Bunit.Rendering; /// public sealed class RenderEvent { - private readonly RenderBatch renderBatch; + private readonly Dictionary statuses = new(); + + internal IReadOnlyDictionary Statuses => statuses; /// /// Gets a collection of , accessible via the ID /// of the component they are created by. /// - public RenderTreeFrameDictionary Frames { get; } - - /// - /// Initializes a new instance of the class. - /// - /// The update from the render event. - /// The from the current render. - internal RenderEvent(RenderBatch renderBatch, RenderTreeFrameDictionary frames) - { - this.renderBatch = renderBatch; - Frames = frames; - } + public RenderTreeFrameDictionary Frames { get; } = new(); /// /// Gets the render status for a . @@ -34,86 +25,57 @@ internal RenderEvent(RenderBatch renderBatch, RenderTreeFrameDictionary frames) if (renderedComponent is null) throw new ArgumentNullException(nameof(renderedComponent)); - var result = (Rendered: false, Changed: false, Disposed: false); + return statuses.TryGetValue(renderedComponent.ComponentId, out var status) + ? (status.Rendered, status.Changed, status.Disposed) + : (Rendered: false, Changed: false, Disposed: false); + } - if (DidComponentDispose(renderedComponent)) - { - result.Disposed = true; - } - else + internal Status GetOrCreateStatus(int componentId) + { + if (!statuses.TryGetValue(componentId, out var status)) { - (result.Rendered, result.Changed) = GetRenderAndChangeStatus(renderedComponent); + status = new(); + statuses[componentId] = status; } + return status; + } - return result; + internal void SetDisposed(int componentId) + { + GetOrCreateStatus(componentId).Disposed = true; } - private bool DidComponentDispose(IRenderedFragmentBase renderedComponent) + internal void SetUpdated(int componentId, bool hasChanges) { - for (var i = 0; i < renderBatch.DisposedComponentIDs.Count; i++) - { - if (renderBatch.DisposedComponentIDs.Array[i].Equals(renderedComponent.ComponentId)) - { - return true; - } - } + var status = GetOrCreateStatus(componentId); + status.Rendered = true; + status.Changed = hasChanges; + } - return false; + internal void SetUpdatedApplied(int componentId) + { + GetOrCreateStatus(componentId).UpdatesApplied = true; } - /// - /// This method determines if the or any of the - /// components underneath it in the render tree rendered and whether they they changed - /// their render tree during render. - /// - /// It does this by getting the status from the , - /// then from all its children, using a recursive pattern, where the internal methods - /// GetStatus and GetStatusFromChildren call each other until there are no more children, - /// or both a render and a change is found. - /// - private (bool Rendered, bool HasChanges) GetRenderAndChangeStatus(IRenderedFragmentBase renderedComponent) + internal void AddFrames(int componentId, ArrayRange frames) { - var result = (Rendered: false, HasChanges: false); + Frames.Add(componentId, frames); + GetOrCreateStatus(componentId).FramesLoaded = true; + } - GetStatus(renderedComponent.ComponentId); + internal record class Status + { + public bool Rendered { get; set; } - return result; + public bool Changed { get; set; } - void GetStatus(int componentId) - { - for (var i = 0; i < renderBatch.UpdatedComponents.Count; i++) - { - ref var update = ref renderBatch.UpdatedComponents.Array[i]; - if (update.ComponentId == componentId) - { - result.Rendered = true; - result.HasChanges = update.Edits.Count > 0; - break; - } - } - - if (!result.HasChanges) - { - GetStatusFromChildren(componentId); - } - } + public bool Disposed { get; set; } - void GetStatusFromChildren(int componentId) - { - var frames = Frames[componentId]; - for (var i = 0; i < frames.Count; i++) - { - ref var frame = ref frames.Array[i]; - if (frame.FrameType == RenderTreeFrameType.Component) - { - GetStatus(frame.ComponentId); - - if (result.HasChanges) - { - break; - } - } - } - } + public bool UpdatesApplied { get; set; } + + public bool FramesLoaded { get; set; } + + public bool UpdateNeeded => Rendered || Changed; } } + diff --git a/src/bunit.core/Rendering/TestRenderer.cs b/src/bunit.core/Rendering/TestRenderer.cs index b21570bd2..92cbc5765 100644 --- a/src/bunit.core/Rendering/TestRenderer.cs +++ b/src/bunit.core/Rendering/TestRenderer.cs @@ -1,6 +1,6 @@ +using Microsoft.Extensions.Logging; using System.Reflection; using System.Runtime.ExceptionServices; -using Microsoft.Extensions.Logging; namespace Bunit.Rendering; @@ -113,12 +113,16 @@ public Task DispatchEventAsync( // if the event contains associated data. lock (renderTreeUpdateLock) { + if (disposed) + throw new ObjectDisposedException(nameof(TestRenderer)); + var result = Dispatcher.InvokeAsync(() => { ResetUnhandledException(); try { + logger.LogDispatchingEvent(eventHandlerId, fieldInfo, eventArgs); return base.DispatchEventAsync(eventHandlerId, fieldInfo, eventArgs); } catch (ArgumentException ex) when (string.Equals(ex.Message, $"There is no event handler associated with this event. EventId: '{eventHandlerId}'. (Parameter 'eventHandlerId')", StringComparison.Ordinal)) @@ -165,55 +169,69 @@ public void DisposeComponents() if (disposed) throw new ObjectDisposedException(nameof(TestRenderer)); - // The dispatcher will always return a completed task, - // when dealing with an IAsyncDisposable. - // Therefore checking for a completed task and awaiting it - // will only work on IDisposable - var disposeTask = Dispatcher.InvokeAsync(() => + lock (renderTreeUpdateLock) { - ResetUnhandledException(); - - foreach (var root in rootComponents) + // The dispatcher will always return a completed task, + // when dealing with an IAsyncDisposable. + // Therefore checking for a completed task and awaiting it + // will only work on IDisposable + Dispatcher.InvokeAsync(() => { - root.Detach(); - } - }); + ResetUnhandledException(); - if (!disposeTask.IsCompleted) - { - disposeTask.GetAwaiter().GetResult(); - } + foreach (var root in rootComponents) + { + root.Detach(); + } + }); - rootComponents.Clear(); - AssertNoUnhandledExceptions(); + rootComponents.Clear(); + AssertNoUnhandledExceptions(); + } } /// internal void SetDirectParameters(IRenderedFragmentBase renderedComponent, ParameterView parameters) { - Dispatcher.InvokeAsync(() => + if (disposed) + throw new ObjectDisposedException(nameof(TestRenderer)); + + // Calling SetDirectParameters updates the render tree + // if the event contains associated data. + lock (renderTreeUpdateLock) { - try - { - IsBatchInProgress = true; + if (disposed) + throw new ObjectDisposedException(nameof(TestRenderer)); - var componentState = GetRequiredComponentStateMethod.Invoke(this, new object[] { renderedComponent.ComponentId })!; - var setDirectParametersMethod = componentState.GetType().GetMethod("SetDirectParameters", BindingFlags.Public | BindingFlags.Instance)!; - setDirectParametersMethod.Invoke(componentState, new object[] { parameters }); - } - catch (TargetInvocationException ex) when (ex.InnerException is not null) + var result = Dispatcher.InvokeAsync(() => { - HandleException(ex.InnerException); - } - finally + try + { + IsBatchInProgress = true; + + var componentState = GetRequiredComponentStateMethod.Invoke(this, new object[] { renderedComponent.ComponentId })!; + var setDirectParametersMethod = componentState.GetType().GetMethod("SetDirectParameters", BindingFlags.Public | BindingFlags.Instance)!; + setDirectParametersMethod.Invoke(componentState, new object[] { parameters }); + } + catch (TargetInvocationException ex) when (ex.InnerException is not null) + { + throw ex.InnerException; + } + finally + { + IsBatchInProgress = false; + } + + ProcessPendingRender(); + }); + + if (result.IsFaulted && result.Exception is not null) { - IsBatchInProgress = false; + HandleException(result.Exception); } - ProcessPendingRender(); - }); - - AssertNoUnhandledExceptions(); + AssertNoUnhandledExceptions(); + } } /// @@ -231,6 +249,12 @@ protected override void ProcessPendingRender() // so there is no need to lock in that method. lock (renderTreeUpdateLock) { + if (disposed) + { + logger.LogRenderCycleActiveAfterDispose(); + return; + } + base.ProcessPendingRender(); } } @@ -238,86 +262,139 @@ protected override void ProcessPendingRender() /// protected override Task UpdateDisplayAsync(in RenderBatch renderBatch) { - if (disposed) + var renderEvent = new RenderEvent(); + PrepareRenderEvent(renderBatch); + InvokeApplyRenderEvent(); + + return Task.CompletedTask; + + void PrepareRenderEvent(in RenderBatch renderBatch) { - logger.LogRenderCycleActiveAfterDispose(); - return Task.CompletedTask; + for (var i = 0; i < renderBatch.DisposedComponentIDs.Count; i++) + { + var id = renderBatch.DisposedComponentIDs.Array[i]; + renderEvent.SetDisposed(id); + } + + for (int i = 0; i < renderBatch.UpdatedComponents.Count; i++) + { + ref var update = ref renderBatch.UpdatedComponents.Array[i]; + renderEvent.SetUpdated(update.ComponentId, update.Edits.Count > 0); + } + + foreach (var (_, rc) in renderedComponents) + { + LoadChangesIntoRenderEvent(rc.ComponentId); + } } - if (usersSyncContext is not null && usersSyncContext != SynchronizationContext.Current) + void LoadChangesIntoRenderEvent(int componentId) { - // The users' sync context, typically one established by - // xUnit or another testing framework is used to update any - // rendered fragments/dom trees and trigger WaitForX handlers. - // This ensures that changes to DOM observed inside a WaitForX handler - // will also be visible outside a WaitForX handler, since - // they will be running in the same sync context. The theory is that - // this should mitigate the issues where Blazor's dispatcher/thread is used - // to verify an assertion inside a WaitForX handler, and another thread is - // used again to access the DOM/repeat the assertion, where the change - // may not be visible yet (another theory about why that may happen is different - // CPU cache updates not happening immediately). - // - // There is no guarantee a caller/test framework has set a sync context. - usersSyncContext.Send(static (state) => + var status = renderEvent.GetOrCreateStatus(componentId); + if (status.FramesLoaded || status.Disposed) + return; + + var frames = GetCurrentRenderTreeFrames(componentId); + renderEvent.AddFrames(componentId, frames); + + for (var i = 0; i < frames.Count; i++) { - var (renderBatch, renderer) = ((RenderBatch, TestRenderer))state!; - renderer.UpdateDisplay(renderBatch); - }, (renderBatch, this)); + ref var frame = ref frames.Array[i]; + if (frame.FrameType == RenderTreeFrameType.Component) + { + // If a child component of the current components has been + // disposed, there is no reason to load the disposed components + // render tree frames. This can also cause a stack overflow if + // the current component was previously a child of the disposed + // component (is that possible?) + var childStatus = renderEvent.GetOrCreateStatus(frame.ComponentId); + if (childStatus.Disposed) + { + logger.LogDisposedChildInRenderTreeFrame(componentId, frame.ComponentId); + } + // The assumption is that a component cannot be in multiple places at + // once. However, in case this is not a correct assumption, this + // ensures that a child components frames are only loaded once. + else if (!renderEvent.GetOrCreateStatus(frame.ComponentId).FramesLoaded) + { + LoadChangesIntoRenderEvent(frame.ComponentId); + } + + if (childStatus.Rendered || childStatus.Changed || childStatus.Disposed) + { + status.Rendered = status.Rendered || childStatus.Rendered; + + // The current component should also be marked as changed if the child component is + // either changed or disposed, as there is a good chance that the child component + // contained markup which is no longer visible. + status.Changed = status.Changed || childStatus.Changed || childStatus.Disposed; + } + } + } } - else + + void InvokeApplyRenderEvent() { - UpdateDisplay(renderBatch); + if (usersSyncContext is not null && usersSyncContext != SynchronizationContext.Current) + { + // The users' sync context, typically one established by + // xUnit or another testing framework is used to update any + // rendered fragments/dom trees and trigger WaitForX handlers. + // This ensures that changes to DOM observed inside a WaitForX handler + // will also be visible outside a WaitForX handler, since + // they will be running in the same sync context. The theory is that + // this should mitigate the issues where Blazor's dispatcher/thread is used + // to verify an assertion inside a WaitForX handler, and another thread is + // used again to access the DOM/repeat the assertion, where the change + // may not be visible yet (another theory about why that may happen is different + // CPU cache updates not happening immediately). + // + // There is no guarantee a caller/test framework has set a sync context. + usersSyncContext.Send(_ => ApplyRenderEvent(renderEvent), null); + } + else + { + ApplyRenderEvent(renderEvent); + } } - - return Task.CompletedTask; } - private void UpdateDisplay(in RenderBatch renderBatch) + private void ApplyRenderEvent(RenderEvent renderEvent) { RenderCount++; - var renderEvent = new RenderEvent(renderBatch, new RenderTreeFrameDictionary()); - if (disposed) + foreach (var (componentId, status) in renderEvent.Statuses) { - logger.LogRenderCycleActiveAfterDispose(); - return; - } - - // removes disposed components - for (var i = 0; i < renderBatch.DisposedComponentIDs.Count; i++) - { - var id = renderBatch.DisposedComponentIDs.Array[i]; - - // Add disposed components to the frames collection - // to avoid them being added into the dictionary later during a - // LoadRenderTreeFrames/GetOrLoadRenderTreeFrame call. - renderEvent.Frames.Add(id, default); - - logger.LogComponentDisposed(id); + if (status.UpdatesApplied || !renderedComponents.TryGetValue(componentId, out var rc)) + { + continue; + } - if (renderedComponents.TryGetValue(id, out var rc)) + if (status.Disposed) { - renderedComponents.Remove(id); + renderedComponents.Remove(componentId); rc.OnRender(renderEvent); + renderEvent.SetUpdatedApplied(componentId); + logger.LogComponentDisposed(componentId); + continue; } - } - // notify each rendered component about the render - foreach (var (key, rc) in renderedComponents.ToArray()) - { - LoadRenderTreeFrames(rc.ComponentId, renderEvent.Frames); - - rc.OnRender(renderEvent); + if (status.UpdateNeeded) + { + rc.OnRender(renderEvent); + renderEvent.SetUpdatedApplied(componentId); - logger.LogComponentRendered(rc.ComponentId); + // RC can replace the instance of the component it is bound + // to while processing the update event, e.g. during the + // initial render of a component. + if (componentId != rc.ComponentId) + { + renderedComponents.Remove(componentId); + renderedComponents.Add(rc.ComponentId, rc); + renderEvent.SetUpdatedApplied(rc.ComponentId); + } - // RC can replace the instance of the component it is bound - // to while processing the update event. - if (key != rc.ComponentId) - { - renderedComponents.Remove(key); - renderedComponents.Add(rc.ComponentId, rc); + logger.LogComponentRendered(rc.ComponentId); } } } @@ -328,10 +405,13 @@ protected override void Dispose(bool disposing) if (disposed) return; - disposed = true; - lock (renderTreeUpdateLock) { + if (disposed) + return; + + disposed = true; + if (disposing) { foreach (var rc in renderedComponents.Values) @@ -401,6 +481,9 @@ private IReadOnlyList> FindComponents GetOrLoadRenderTreeFrame(RenderTreeFrameDict } /// - protected override void HandleException(Exception exception) + protected override void HandleException([NotNull] Exception exception) { - if (exception is null || disposed) + if (disposed) return; logger.LogUnhandledException(exception); @@ -508,17 +591,26 @@ private void ResetUnhandledException() private void AssertNoUnhandledExceptions() { - if (capturedUnhandledException is Exception unhandled && !disposed) + // Ensure we are not throwing an exception while a render is ongoing. + // This could lead to the renderer being disposed which could lead to + // tests failing that should not be failing. + lock (renderTreeUpdateLock) { - capturedUnhandledException = null; + if (disposed) + return; - if (unhandled is AggregateException aggregateException && aggregateException.InnerExceptions.Count == 1) - { - ExceptionDispatchInfo.Capture(aggregateException.InnerExceptions[0]).Throw(); - } - else + if (capturedUnhandledException is { } unhandled) { - ExceptionDispatchInfo.Capture(unhandled).Throw(); + capturedUnhandledException = null; + + if (unhandled is AggregateException { InnerExceptions.Count: 1 } aggregateException) + { + ExceptionDispatchInfo.Capture(aggregateException.InnerExceptions[0]).Throw(); + } + else + { + ExceptionDispatchInfo.Capture(unhandled).Throw(); + } } } } diff --git a/src/bunit.core/Rendering/TestRendererLoggerExtensions.cs b/src/bunit.core/Rendering/TestRendererLoggerExtensions.cs index 557705aaf..1960677f9 100644 --- a/src/bunit.core/Rendering/TestRendererLoggerExtensions.cs +++ b/src/bunit.core/Rendering/TestRendererLoggerExtensions.cs @@ -1,51 +1,15 @@ using Microsoft.Extensions.Logging; +using System.Text.Json; namespace Bunit.Rendering; internal static class TestRendererLoggerExtensions { - private static readonly Action ProcessingPendingRenders - = LoggerMessage.Define(LogLevel.Debug, new EventId(1, "ProcessPendingRender"), "Processing pending renders."); - - private static readonly Action NewRenderBatchReceived - = LoggerMessage.Define(LogLevel.Debug, new EventId(10, "UpdateDisplayAsync"), "New render batch received."); - private static readonly Action ComponentDisposed - = LoggerMessage.Define(LogLevel.Debug, new EventId(11, "UpdateDisplayAsync"), "Component {Id} has been disposed."); - - private static readonly Action ComponentRendered - = LoggerMessage.Define(LogLevel.Debug, new EventId(12, "UpdateDisplayAsync"), "Component {Id} has been rendered."); - - private static readonly Action ChangedComponentsMarkupUpdated - = LoggerMessage.Define(LogLevel.Debug, new EventId(13, "UpdateDisplayAsync"), "Finished updating the markup of changed components."); - - private static readonly Action AsyncInitialRender - = LoggerMessage.Define(LogLevel.Debug, new EventId(20, "Render"), "The initial render task did not complete immediately."); - - private static readonly Action InitialRenderCompleted - = LoggerMessage.Define(LogLevel.Debug, new EventId(21, "UpdateDisplayAsync"), "The initial render of component {Id} is completed."); - - private static readonly Action UnhandledException - = LoggerMessage.Define(LogLevel.Error, new EventId(30, "LogUnhandledException"), "An unhandled exception happened during rendering: {Message}" + Environment.NewLine + "{StackTrace}"); - - private static readonly Action RenderCycleActiveAfterDispose - = LoggerMessage.Define(LogLevel.Warning, new EventId(31, "LogRenderCycleActiveAfterDispose"), "A component attempted to update the render tree after the renderer was disposed."); - - internal static void LogProcessingPendingRenders(this ILogger logger) - { - if (logger.IsEnabled(LogLevel.Debug)) - { - ProcessingPendingRenders(logger, null); - } - } - - internal static void LogNewRenderBatchReceived(this ILogger logger) - { - if (logger.IsEnabled(LogLevel.Debug)) - { - NewRenderBatchReceived(logger, null); - } - } + = LoggerMessage.Define( + LogLevel.Debug, + new EventId(11, "ComponentDisposed"), + "Component {Id} has been disposed."); internal static void LogComponentDisposed(this ILogger logger, int componentId) { @@ -55,6 +19,12 @@ internal static void LogComponentDisposed(this ILogger logger, int } } + private static readonly Action ComponentRendered + = LoggerMessage.Define( + LogLevel.Debug, + new EventId(12, "ComponentRendered"), + "Component {ComponentId} has been rendered."); + internal static void LogComponentRendered(this ILogger logger, int componentId) { if (logger.IsEnabled(LogLevel.Debug)) @@ -63,14 +33,26 @@ internal static void LogComponentRendered(this ILogger logger, int } } - internal static void LogChangedComponentsMarkupUpdated(this ILogger logger) + private static readonly Action DisposedChildInRenderTreeFrame + = LoggerMessage.Define( + LogLevel.Warning, + new EventId(14, "DisposedChildInRenderTreeFrame"), + "A parent components {ParentComponentId} has a disposed component {ComponentId} as its child."); + + internal static void LogDisposedChildInRenderTreeFrame(this ILogger logger, int parentComponentId, int componentId) { - if (logger.IsEnabled(LogLevel.Debug)) + if (logger.IsEnabled(LogLevel.Warning)) { - ChangedComponentsMarkupUpdated(logger, null); + DisposedChildInRenderTreeFrame(logger, parentComponentId, componentId, null); } } + private static readonly Action AsyncInitialRender + = LoggerMessage.Define( + LogLevel.Debug, + new EventId(20, "AsyncInitialRender"), + "The initial render task did not complete immediately."); + internal static void LogAsyncInitialRender(this ILogger logger) { if (logger.IsEnabled(LogLevel.Debug)) @@ -79,6 +61,12 @@ internal static void LogAsyncInitialRender(this ILogger logger) } } + private static readonly Action InitialRenderCompleted + = LoggerMessage.Define( + LogLevel.Debug, + new EventId(21, "InitialRenderCompleted"), + "The initial render of component {ComponentId} is completed."); + internal static void LogInitialRenderCompleted(this ILogger logger, int componentId) { if (logger.IsEnabled(LogLevel.Debug)) @@ -87,6 +75,12 @@ internal static void LogInitialRenderCompleted(this ILogger logger } } + private static readonly Action UnhandledException + = LoggerMessage.Define( + LogLevel.Error, + new EventId(30, "UnhandledException"), + "An unhandled exception happened during rendering: {Message}" + Environment.NewLine + "{StackTrace}"); + internal static void LogUnhandledException(this ILogger logger, Exception exception) { if (logger.IsEnabled(LogLevel.Error)) @@ -95,6 +89,12 @@ internal static void LogUnhandledException(this ILogger logger, Ex } } + private static readonly Action RenderCycleActiveAfterDispose + = LoggerMessage.Define( + LogLevel.Warning, + new EventId(31, "RenderCycleActiveAfterDispose"), + "A component attempted to update the render tree after the renderer was disposed."); + internal static void LogRenderCycleActiveAfterDispose(this ILogger logger) { if (logger.IsEnabled(LogLevel.Warning)) @@ -102,4 +102,43 @@ internal static void LogRenderCycleActiveAfterDispose(this ILogger RenderCycleActiveAfterDispose(logger, null); } } + + private static readonly Action DispatchingEventWithFieldValue + = LoggerMessage.Define( + LogLevel.Debug, + new EventId(40, "DispatchingEvent"), + "Dispatching {EventArgs} to {FieldValue} handler (id = {EventHandlerId}) on component {ComponentId}."); + + private static readonly Action DispatchingEvent + = LoggerMessage.Define( + LogLevel.Debug, + new EventId(40, "DispatchingEvent"), + "Dispatching {EventArgs} to handler (id = {EventHandlerId}) on component {ComponentId}."); + + internal static void LogDispatchingEvent(this ILogger logger, ulong eventHandlerId, EventFieldInfo fieldInfo, EventArgs eventArgs) + { + if (logger.IsEnabled(LogLevel.Debug)) + { + var eventType = eventArgs.GetType(); + var eventArgsText = eventType.Name; + if (eventArgsText != nameof(EventArgs)) + { + var eventArgsContent = JsonSerializer.Serialize(eventArgs, eventType); + eventArgsText = eventArgsContent == "{}" + ? eventArgsText + : $"{eventArgsText} = {eventArgsContent}"; + } + + if (fieldInfo.FieldValue is not null) + { + var fieldValueText = JsonSerializer.Serialize(fieldInfo.FieldValue, fieldInfo.FieldValue.GetType()); + DispatchingEventWithFieldValue(logger, eventArgsText, fieldValueText, eventHandlerId, fieldInfo.ComponentId, null); + } + else + { + DispatchingEvent(logger, eventArgsText, eventHandlerId, fieldInfo.ComponentId, null); + } + } + } + } diff --git a/src/bunit.web/TestDoubles/ErrorBoundary/BunitErrorBoundaryLogger.cs b/src/bunit.web/TestDoubles/ErrorBoundary/BunitErrorBoundaryLogger.cs index d3607929d..8fd109bee 100644 --- a/src/bunit.web/TestDoubles/ErrorBoundary/BunitErrorBoundaryLogger.cs +++ b/src/bunit.web/TestDoubles/ErrorBoundary/BunitErrorBoundaryLogger.cs @@ -1,7 +1,4 @@ #if NET6_0_OR_GREATER -using System; -using System.Threading.Tasks; -using Microsoft.AspNetCore.Components.Web; using Microsoft.Extensions.Logging; namespace Bunit.TestDoubles; @@ -12,10 +9,8 @@ namespace Bunit.TestDoubles; /// internal class BunitErrorBoundaryLogger : IErrorBoundaryLogger { - private static readonly Action ExceptionCaughtByErrorBoundary = LoggerMessage.Define( - LogLevel.Warning, - 100, - "Unhandled exception rendering component: {Message}"); + private static readonly Action ExceptionCaughtByErrorBoundary + = LoggerMessage.Define(LogLevel.Warning, new EventId(100, "ExceptionCaughtByErrorBoundary"), "Unhandled exception rendering component: {Message}"); private readonly ILogger logger; diff --git a/tests/Directory.Build.props b/tests/Directory.Build.props index 9c7deed55..af5373d70 100644 --- a/tests/Directory.Build.props +++ b/tests/Directory.Build.props @@ -42,6 +42,7 @@ + diff --git a/tests/bunit.core.tests/Rendering/TestRendererTest.cs b/tests/bunit.core.tests/Rendering/TestRendererTest.cs index 3d3016757..7856ca0a5 100644 --- a/tests/bunit.core.tests/Rendering/TestRendererTest.cs +++ b/tests/bunit.core.tests/Rendering/TestRendererTest.cs @@ -455,6 +455,79 @@ public void Test206() child.RenderCount.ShouldBe(2); } + [Fact(DisplayName = "Multiple calls to StateHasChanged from OnParametersSet with Render")] + public void Test207() + { + var cut = RenderComponent(); + cut.RenderCount.ShouldBe(1); + + cut.Render(); + + cut.RenderCount.ShouldBe(2); + cut.Instance.InitilizedCount.ShouldBe(1); + cut.Instance.InitilizedAsyncCount.ShouldBe(1); + cut.Instance.ParametersSetCount.ShouldBe(2); + cut.Instance.ParametersSetAsyncCount.ShouldBe(2); + cut.Instance.AfterRenderCount.ShouldBe(2); + cut.Instance.AfterRenderAsyncCount.ShouldBe(2); + } + + [Fact(DisplayName = "Multiple calls to StateHasChanged from OnParametersSet with Render")] + public void Test208() + { + var cut = RenderComponent(); + cut.RenderCount.ShouldBe(1); + + cut.SetParametersAndRender(); + + cut.RenderCount.ShouldBe(2); + cut.Instance.InitilizedCount.ShouldBe(1); + cut.Instance.InitilizedAsyncCount.ShouldBe(1); + cut.Instance.ParametersSetCount.ShouldBe(2); + cut.Instance.ParametersSetAsyncCount.ShouldBe(2); + cut.Instance.AfterRenderCount.ShouldBe(2); + cut.Instance.AfterRenderAsyncCount.ShouldBe(2); + } + + internal sealed class LifeCycleMethodInvokeCounter : ComponentBase + { + public int InitilizedCount { get; private set; } + + public int InitilizedAsyncCount { get; private set; } + + public int ParametersSetCount { get; private set; } + public int ParametersSetAsyncCount { get; private set; } + public int AfterRenderCount { get; private set; } + public int AfterRenderAsyncCount { get; private set; } + + protected override void OnInitialized() + => InitilizedCount++; + + protected override Task OnInitializedAsync() + { + InitilizedAsyncCount++; + return Task.CompletedTask; + } + + protected override void OnParametersSet() + => ParametersSetCount++; + + protected override Task OnParametersSetAsync() + { + ParametersSetAsyncCount++; + return Task.CompletedTask; + } + + protected override void OnAfterRender(bool firstRender) + => AfterRenderCount++; + + protected override Task OnAfterRenderAsync(bool firstRender) + { + AfterRenderAsyncCount++; + return Task.CompletedTask; + } + } + internal sealed class NoChildNoParams : ComponentBase { public const string MARKUP = "hello world"; diff --git a/tests/bunit.testassets/ServiceCollectionLoggingExtensions.cs b/tests/bunit.testassets/ServiceCollectionLoggingExtensions.cs index d469c62b0..4369522b4 100644 --- a/tests/bunit.testassets/ServiceCollectionLoggingExtensions.cs +++ b/tests/bunit.testassets/ServiceCollectionLoggingExtensions.cs @@ -1,40 +1,25 @@ -using System.Globalization; using Microsoft.Extensions.Logging; using Serilog; -using Serilog.Core; using Serilog.Events; +using Serilog.Templates; using Xunit.Abstractions; namespace Xunit; public static class ServiceCollectionLoggingExtensions { - [SuppressMessage("Reliability", "CA2000:Dispose objects before losing scope", Justification = "Serilog should dispose of its logger itself")] public static IServiceCollection AddXunitLogger(this IServiceCollection services, ITestOutputHelper outputHelper) { var serilogLogger = new LoggerConfiguration() .MinimumLevel.Verbose() - .Enrich.With(new ThreadIDEnricher()) .WriteTo.TestOutput( testOutputHelper: outputHelper, - restrictedToMinimumLevel: LogEventLevel.Verbose, - outputTemplate: ThreadIDEnricher.DefaultConsoleOutputTemplate, - formatProvider: CultureInfo.InvariantCulture) + formatter: new ExpressionTemplate("[{UtcDateTime(@t):mm:ss.ffffff} | {@l:u3} | {Substring(SourceContext, LastIndexOf(SourceContext, '.') + 1)} | {Coalesce(EventId.Name, '')}] {@m}\n{@x}"), + restrictedToMinimumLevel: LogEventLevel.Verbose) .CreateLogger(); - services.AddSingleton(new LoggerFactory().AddSerilog(serilogLogger, dispose: true)); + services.AddSingleton(_ => new LoggerFactory().AddSerilog(serilogLogger, dispose: true)); services.AddSingleton(typeof(ILogger<>), typeof(Logger<>)); return services; } - - private sealed class ThreadIDEnricher : ILogEventEnricher - { - internal const string DefaultConsoleOutputTemplate = "{Timestamp:yyyy-MM-dd HH:mm:ss} ({ThreadID}) [{Level}] {Message}{NewLine}{Exception}"; - - public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) - { - logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty( - "ThreadID", Environment.CurrentManagedThreadId.ToString("D4", CultureInfo.InvariantCulture))); - } - } } diff --git a/tests/bunit.testassets/bunit.testassets.csproj b/tests/bunit.testassets/bunit.testassets.csproj index 50aa940b2..92ce4b7af 100644 --- a/tests/bunit.testassets/bunit.testassets.csproj +++ b/tests/bunit.testassets/bunit.testassets.csproj @@ -14,6 +14,7 @@ + diff --git a/tests/bunit.web.testcomponents.tests/bunit.web.testcomponents.tests.csproj b/tests/bunit.web.testcomponents.tests/bunit.web.testcomponents.tests.csproj index 6bbbe3330..0ba8e238c 100644 --- a/tests/bunit.web.testcomponents.tests/bunit.web.testcomponents.tests.csproj +++ b/tests/bunit.web.testcomponents.tests/bunit.web.testcomponents.tests.csproj @@ -11,7 +11,7 @@ - + NU1605 diff --git a/tests/bunit.web.tests/EventDispatchExtensions/ClipboardEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/ClipboardEventDispatchExtensionsTest.cs index dc61cbf4d..2e4e267ee 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/ClipboardEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/ClipboardEventDispatchExtensionsTest.cs @@ -1,7 +1,13 @@ +using Xunit.Abstractions; + namespace Bunit; public class ClipboardEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public ClipboardEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + protected override string ElementName => "textarea"; [Theory(DisplayName = "Clipboard events are raised correctly through helpers")] diff --git a/tests/bunit.web.tests/EventDispatchExtensions/DetailsElementEventDispatcherExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/DetailsElementEventDispatcherExtensionsTest.cs index 4b5fe904c..9eaeb5c50 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/DetailsElementEventDispatcherExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/DetailsElementEventDispatcherExtensionsTest.cs @@ -1,7 +1,4 @@ #if !NETCOREAPP3_1 -using Bunit.TestAssets.SampleComponents; -using Shouldly; -using Xunit; namespace Bunit.EventDispatchExtensions; diff --git a/tests/bunit.web.tests/EventDispatchExtensions/DragEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/DragEventDispatchExtensionsTest.cs index 12f65f3cd..fbb6d7f95 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/DragEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/DragEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class DragEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public DragEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + protected override string ElementName => "textarea"; [Theory(DisplayName = "Drag events are raised correctly through helpers")] diff --git a/tests/bunit.web.tests/EventDispatchExtensions/EventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/EventDispatchExtensionsTest.cs index 31f6bb1d8..a0fa9cc89 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/EventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/EventDispatchExtensionsTest.cs @@ -1,4 +1,5 @@ using AngleSharp.Dom; +using Xunit.Abstractions; namespace Bunit; @@ -9,6 +10,11 @@ public abstract class EventDispatchExtensionsTest : TestContext protected abstract string ElementName { get; } + protected EventDispatchExtensionsTest(ITestOutputHelper outputHelper) + { + Services.AddXunitLogger(outputHelper); + } + protected TriggerEventSpy CreateTriggerSpy(string element, string eventName) => new(p => RenderComponent>(p), element, eventName); diff --git a/tests/bunit.web.tests/EventDispatchExtensions/FocusEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/FocusEventDispatchExtensionsTest.cs index 5962fb6e9..6fc79f930 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/FocusEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/FocusEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class FocusEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public FocusEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + protected override string ElementName => "p"; [Theory(DisplayName = "Focus events are raised correctly through helpers")] diff --git a/tests/bunit.web.tests/EventDispatchExtensions/GeneralEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/GeneralEventDispatchExtensionsTest.cs index a8d5e112c..a69b55aca 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/GeneralEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/GeneralEventDispatchExtensionsTest.cs @@ -1,7 +1,6 @@ using AngleSharp; using AngleSharp.Dom; using Bunit.Rendering; -using Xunit.Abstractions; namespace Bunit; @@ -10,9 +9,9 @@ public class GeneralEventDispatchExtensionsTest : EventDispatchExtensionsTest "p"; public GeneralEventDispatchExtensionsTest(ITestOutputHelper outputHelper) + : base(outputHelper) { TestContext.DefaultWaitTimeout = TimeSpan.FromSeconds(30); - Services.AddXunitLogger(outputHelper); } [Theory(DisplayName = "General events are raised correctly through helpers")] @@ -342,8 +341,8 @@ public async Task Test400(int repeatCount) // reliably. [SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Needed to trigger multiple reruns of test.")] [Theory(DisplayName = "TriggerEventAsync avoids race condition with DOM tree updates")] - [Repeat(10)] - [Trait("Category", "sync")] + [Repeat(10)] + [Trait("Category", "sync")] public async Task Test400_Sync(int repeatCount) { var cut = RenderComponent(); diff --git a/tests/bunit.web.tests/EventDispatchExtensions/InputEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/InputEventDispatchExtensionsTest.cs index 1b134b25f..f96c9107c 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/InputEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/InputEventDispatchExtensionsTest.cs @@ -11,6 +11,10 @@ public class InputEventDispatchExtensionsTest : EventDispatchExtensionsTest "input"; + public InputEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + [Theory(DisplayName = "Input events are raised correctly through helpers")] [MemberData(nameof(Helpers))] public void CanRaiseEvents(MethodInfo helper) diff --git a/tests/bunit.web.tests/EventDispatchExtensions/KeyboardEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/KeyboardEventDispatchExtensionsTest.cs index 5c07c2fc4..e5c7c465d 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/KeyboardEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/KeyboardEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class KeyboardEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public KeyboardEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + public static IEnumerable Helpers { get; } = GetEventHelperMethods( typeof(KeyboardEventDispatchExtensions), diff --git a/tests/bunit.web.tests/EventDispatchExtensions/MediaEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/MediaEventDispatchExtensionsTest.cs index bb2fd5578..3ee3153a5 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/MediaEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/MediaEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class MediaEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public MediaEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + protected override string ElementName => "audio"; [Theory(DisplayName = "Media events are raised correctly through helpers")] diff --git a/tests/bunit.web.tests/EventDispatchExtensions/MouseEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/MouseEventDispatchExtensionsTest.cs index 7b8615a65..03d562b06 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/MouseEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/MouseEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class MouseEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public MouseEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + public static IEnumerable Helpers { get; } = GetEventHelperMethods( typeof(MouseEventDispatchExtensions), diff --git a/tests/bunit.web.tests/EventDispatchExtensions/PointerEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/PointerEventDispatchExtensionsTest.cs index 3f1f0e7a8..bc239a37d 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/PointerEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/PointerEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class PointerEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public PointerEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + protected override string ElementName => "div"; [Theory(DisplayName = "Pointer events are raised correctly through helpers")] diff --git a/tests/bunit.web.tests/EventDispatchExtensions/ProgressEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/ProgressEventDispatchExtensionsTest.cs index 8ae6a5c99..ca63db4ed 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/ProgressEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/ProgressEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class ProgressEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public ProgressEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + protected override string ElementName => "div"; [Theory(DisplayName = "Progress events are raised correctly through helpers")] diff --git a/tests/bunit.web.tests/EventDispatchExtensions/TouchEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/TouchEventDispatchExtensionsTest.cs index d4e2a054d..b1e2ce8e2 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/TouchEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/TouchEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class TouchEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public TouchEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + protected override string ElementName => "p"; [Theory(DisplayName = "Touch events are raised correctly through helpers")] diff --git a/tests/bunit.web.tests/EventDispatchExtensions/WheelEventDispatchExtensionsTest.cs b/tests/bunit.web.tests/EventDispatchExtensions/WheelEventDispatchExtensionsTest.cs index cd4a7ff20..dbbb3ea17 100644 --- a/tests/bunit.web.tests/EventDispatchExtensions/WheelEventDispatchExtensionsTest.cs +++ b/tests/bunit.web.tests/EventDispatchExtensions/WheelEventDispatchExtensionsTest.cs @@ -2,6 +2,10 @@ namespace Bunit; public class WheelEventDispatchExtensionsTest : EventDispatchExtensionsTest { + public WheelEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper) + { + } + public static IEnumerable Helpers { get; } = GetEventHelperMethods(typeof(MouseEventDispatchExtensions), x => x.Name.Contains("Wheel", StringComparison.OrdinalIgnoreCase));