Skip to content

Commit 9cdc156

Browse files
egilegil
committed
feat: improve event dispatching logging
1 parent fb40d20 commit 9cdc156

17 files changed

Lines changed: 141 additions & 31 deletions

‎src/bunit.core/Rendering/TestRenderer.cs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -119,6 +119,7 @@ public Task DispatchEventAsync(
119119

120120
try
121121
{
122+
logger.LogDispatchingEvent(eventHandlerId, fieldInfo, eventArgs);
122123
return base.DispatchEventAsync(eventHandlerId, fieldInfo, eventArgs);
123124
}
124125
catch (ArgumentException ex) when (string.Equals(ex.Message, $"There is no event handler associated with this event. EventId: '{eventHandlerId}'. (Parameter 'eventHandlerId')", StringComparison.Ordinal))
@@ -142,7 +143,7 @@ public Task DispatchEventAsync(
142143

143144
return result;
144145
}
145-
}
146+
}
146147

147148
/// <inheritdoc/>
148149
public IRenderedComponentBase<TComponent> FindComponent<TComponent>(IRenderedFragmentBase parentComponent)

‎src/bunit.core/Rendering/TestRendererLoggerExtensions.cs‎

Lines changed: 83 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -1,30 +1,15 @@
11
using Microsoft.Extensions.Logging;
2+
using System.Text.Json;
23

34
namespace Bunit.Rendering;
45

56
internal static class TestRendererLoggerExtensions
67
{
78
private static readonly Action<ILogger, int, Exception?> ComponentDisposed
8-
= LoggerMessage.Define<int>(LogLevel.Debug, new EventId(11, "ComponentDisposed"), "Component {Id} has been disposed.");
9-
10-
private static readonly Action<ILogger, int, Exception?> ComponentRendered
11-
= LoggerMessage.Define<int>(LogLevel.Debug, new EventId(12, "ComponentRendered"), "Component {Id} has been rendered.");
12-
13-
private static readonly Action<ILogger, int, int, Exception?> DisposedChildInRenderTreeFrame
14-
= LoggerMessage.Define<int, int>(LogLevel.Warning, new EventId(14, "DisposedChildInRenderTreeFrame"), "A parent components {ParentComponentId} has a disposed component {ComponentId} as its child.");
15-
16-
private static readonly Action<ILogger, Exception?> AsyncInitialRender
17-
= LoggerMessage.Define(LogLevel.Debug, new EventId(20, "AsyncInitialRender"), "The initial render task did not complete immediately.");
18-
19-
private static readonly Action<ILogger, int, Exception?> InitialRenderCompleted
20-
= LoggerMessage.Define<int>(LogLevel.Debug, new EventId(21, "InitialRenderCompleted"), "The initial render of component {Id} is completed.");
21-
22-
private static readonly Action<ILogger, string, string, Exception> UnhandledException
23-
= LoggerMessage.Define<string, string>(LogLevel.Error, new EventId(30, "UnhandledException"), "An unhandled exception happened during rendering: {Message}" + Environment.NewLine + "{StackTrace}");
24-
25-
private static readonly Action<ILogger, Exception?> RenderCycleActiveAfterDispose
26-
= LoggerMessage.Define(LogLevel.Warning, new EventId(31, "RenderCycleActiveAfterDispose"), "A component attempted to update the render tree after the renderer was disposed.");
27-
9+
= LoggerMessage.Define<int>(
10+
LogLevel.Debug,
11+
new EventId(11, "ComponentDisposed"),
12+
"Component {Id} has been disposed.");
2813

2914
internal static void LogComponentDisposed(this ILogger<TestRenderer> logger, int componentId)
3015
{
@@ -34,6 +19,12 @@ internal static void LogComponentDisposed(this ILogger<TestRenderer> logger, int
3419
}
3520
}
3621

22+
private static readonly Action<ILogger, int, Exception?> ComponentRendered
23+
= LoggerMessage.Define<int>(
24+
LogLevel.Debug,
25+
new EventId(12, "ComponentRendered"),
26+
"Component {ComponentId} has been rendered.");
27+
3728
internal static void LogComponentRendered(this ILogger<TestRenderer> logger, int componentId)
3829
{
3930
if (logger.IsEnabled(LogLevel.Debug))
@@ -42,6 +33,26 @@ internal static void LogComponentRendered(this ILogger<TestRenderer> logger, int
4233
}
4334
}
4435

36+
private static readonly Action<ILogger, int, int, Exception?> DisposedChildInRenderTreeFrame
37+
= LoggerMessage.Define<int, int>(
38+
LogLevel.Warning,
39+
new EventId(14, "DisposedChildInRenderTreeFrame"),
40+
"A parent components {ParentComponentId} has a disposed component {ComponentId} as its child.");
41+
42+
internal static void LogDisposedChildInRenderTreeFrame(this ILogger<TestRenderer> logger, int parentComponentId, int componentId)
43+
{
44+
if (logger.IsEnabled(LogLevel.Warning))
45+
{
46+
DisposedChildInRenderTreeFrame(logger, parentComponentId, componentId, null);
47+
}
48+
}
49+
50+
private static readonly Action<ILogger, Exception?> AsyncInitialRender
51+
= LoggerMessage.Define(
52+
LogLevel.Debug,
53+
new EventId(20, "AsyncInitialRender"),
54+
"The initial render task did not complete immediately.");
55+
4556
internal static void LogAsyncInitialRender(this ILogger<TestRenderer> logger)
4657
{
4758
if (logger.IsEnabled(LogLevel.Debug))
@@ -50,6 +61,12 @@ internal static void LogAsyncInitialRender(this ILogger<TestRenderer> logger)
5061
}
5162
}
5263

64+
private static readonly Action<ILogger, int, Exception?> InitialRenderCompleted
65+
= LoggerMessage.Define<int>(
66+
LogLevel.Debug,
67+
new EventId(21, "InitialRenderCompleted"),
68+
"The initial render of component {ComponentId} is completed.");
69+
5370
internal static void LogInitialRenderCompleted(this ILogger<TestRenderer> logger, int componentId)
5471
{
5572
if (logger.IsEnabled(LogLevel.Debug))
@@ -58,6 +75,12 @@ internal static void LogInitialRenderCompleted(this ILogger<TestRenderer> logger
5875
}
5976
}
6077

78+
private static readonly Action<ILogger, string, string, Exception> UnhandledException
79+
= LoggerMessage.Define<string, string>(
80+
LogLevel.Error,
81+
new EventId(30, "UnhandledException"),
82+
"An unhandled exception happened during rendering: {Message}" + Environment.NewLine + "{StackTrace}");
83+
6184
internal static void LogUnhandledException(this ILogger<TestRenderer> logger, Exception exception)
6285
{
6386
if (logger.IsEnabled(LogLevel.Error))
@@ -66,6 +89,12 @@ internal static void LogUnhandledException(this ILogger<TestRenderer> logger, Ex
6689
}
6790
}
6891

92+
private static readonly Action<ILogger, Exception?> RenderCycleActiveAfterDispose
93+
= LoggerMessage.Define(
94+
LogLevel.Warning,
95+
new EventId(31, "RenderCycleActiveAfterDispose"),
96+
"A component attempted to update the render tree after the renderer was disposed.");
97+
6998
internal static void LogRenderCycleActiveAfterDispose(this ILogger<TestRenderer> logger)
7099
{
71100
if (logger.IsEnabled(LogLevel.Warning))
@@ -74,11 +103,42 @@ internal static void LogRenderCycleActiveAfterDispose(this ILogger<TestRenderer>
74103
}
75104
}
76105

77-
internal static void LogDisposedChildInRenderTreeFrame(this ILogger<TestRenderer> logger, int parentComponentId, int componentId)
106+
private static readonly Action<ILogger, string, string, ulong, int, Exception?> DispatchingEventWithFieldValue
107+
= LoggerMessage.Define<string, string, ulong, int>(
108+
LogLevel.Debug,
109+
new EventId(40, "DispatchingEvent"),
110+
"Dispatching {EventArgs} to {FieldValue} handler (id = {EventHandlerId}) on component {ComponentId}.");
111+
112+
private static readonly Action<ILogger, string, ulong, int, Exception?> DispatchingEvent
113+
= LoggerMessage.Define<string, ulong, int>(
114+
LogLevel.Debug,
115+
new EventId(40, "DispatchingEvent"),
116+
"Dispatching {EventArgs} to handler (id = {EventHandlerId}) on component {ComponentId}.");
117+
118+
internal static void LogDispatchingEvent(this ILogger<TestRenderer> logger, ulong eventHandlerId, EventFieldInfo fieldInfo, EventArgs eventArgs)
78119
{
79-
if (logger.IsEnabled(LogLevel.Warning))
120+
if (logger.IsEnabled(LogLevel.Debug))
80121
{
81-
DisposedChildInRenderTreeFrame(logger, parentComponentId, componentId, null);
122+
var eventType = eventArgs.GetType();
123+
var eventArgsText = eventType.Name;
124+
if (eventArgsText != nameof(EventArgs))
125+
{
126+
var eventArgsContent = JsonSerializer.Serialize(eventArgs, eventType);
127+
eventArgsText = eventArgsContent == "{}"
128+
? eventArgsText
129+
: $"{eventArgsText} = {eventArgsContent}";
130+
}
131+
132+
if (fieldInfo.FieldValue is not null)
133+
{
134+
var fieldValueText = JsonSerializer.Serialize(fieldInfo.FieldValue, fieldInfo.FieldValue.GetType());
135+
DispatchingEventWithFieldValue(logger, eventArgsText, fieldValueText, eventHandlerId, fieldInfo.ComponentId, null);
136+
}
137+
else
138+
{
139+
DispatchingEvent(logger, eventArgsText, eventHandlerId, fieldInfo.ComponentId, null);
140+
}
82141
}
83142
}
143+
84144
}

‎tests/Directory.Build.props‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,7 @@
4242
<Using Include="Moq" />
4343
<Using Include="Shouldly" />
4444
<Using Include="Xunit" />
45+
<Using Include="Xunit.Abstractions" />
4546
</ItemGroup>
4647

4748
</Project>

‎tests/bunit.web.tests/EventDispatchExtensions/ClipboardEventDispatchExtensionsTest.cs‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,13 @@
1+
using Xunit.Abstractions;
2+
13
namespace Bunit;
24

35
public class ClipboardEventDispatchExtensionsTest : EventDispatchExtensionsTest<ClipboardEventArgs>
46
{
7+
public ClipboardEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper)
8+
{
9+
}
10+
511
protected override string ElementName => "textarea";
612

713
[Theory(DisplayName = "Clipboard events are raised correctly through helpers")]

‎tests/bunit.web.tests/EventDispatchExtensions/DetailsElementEventDispatcherExtensionsTest.cs‎

Lines changed: 0 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,4 @@
11
#if !NETCOREAPP3_1
2-
using Bunit.TestAssets.SampleComponents;
3-
using Shouldly;
4-
using Xunit;
52

63
namespace Bunit.EventDispatchExtensions;
74

‎tests/bunit.web.tests/EventDispatchExtensions/DragEventDispatchExtensionsTest.cs‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,10 @@ namespace Bunit;
22

33
public class DragEventDispatchExtensionsTest : EventDispatchExtensionsTest<DragEventArgs>
44
{
5+
public DragEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper)
6+
{
7+
}
8+
59
protected override string ElementName => "textarea";
610

711
[Theory(DisplayName = "Drag events are raised correctly through helpers")]

‎tests/bunit.web.tests/EventDispatchExtensions/EventDispatchExtensionsTest.cs‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
using AngleSharp.Dom;
2+
using Xunit.Abstractions;
23

34
namespace Bunit;
45

@@ -9,6 +10,11 @@ public abstract class EventDispatchExtensionsTest<TEventArgs> : TestContext
910

1011
protected abstract string ElementName { get; }
1112

13+
protected EventDispatchExtensionsTest(ITestOutputHelper outputHelper)
14+
{
15+
Services.AddXunitLogger(outputHelper);
16+
}
17+
1218
protected TriggerEventSpy<EventArgs> CreateTriggerSpy(string element, string eventName)
1319
=> new(p => RenderComponent<TriggerTester<EventArgs>>(p), element, eventName);
1420

‎tests/bunit.web.tests/EventDispatchExtensions/FocusEventDispatchExtensionsTest.cs‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,10 @@ namespace Bunit;
22

33
public class FocusEventDispatchExtensionsTest : EventDispatchExtensionsTest<FocusEventArgs>
44
{
5+
public FocusEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper)
6+
{
7+
}
8+
59
protected override string ElementName => "p";
610

711
[Theory(DisplayName = "Focus events are raised correctly through helpers")]

‎tests/bunit.web.tests/EventDispatchExtensions/GeneralEventDispatchExtensionsTest.cs‎

Lines changed: 3 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,6 @@
11
using AngleSharp;
22
using AngleSharp.Dom;
33
using Bunit.Rendering;
4-
using Xunit.Abstractions;
54

65
namespace Bunit;
76

@@ -10,9 +9,9 @@ public class GeneralEventDispatchExtensionsTest : EventDispatchExtensionsTest<Ev
109
protected override string ElementName => "p";
1110

1211
public GeneralEventDispatchExtensionsTest(ITestOutputHelper outputHelper)
12+
: base(outputHelper)
1313
{
1414
TestContext.DefaultWaitTimeout = TimeSpan.FromSeconds(30);
15-
Services.AddXunitLogger(outputHelper);
1615
}
1716

1817
[Theory(DisplayName = "General events are raised correctly through helpers")]
@@ -342,8 +341,8 @@ public async Task Test400(int repeatCount)
342341
// reliably.
343342
[SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Needed to trigger multiple reruns of test.")]
344343
[Theory(DisplayName = "TriggerEventAsync avoids race condition with DOM tree updates")]
345-
[Repeat(10)]
346-
[Trait("Category", "sync")]
344+
[Repeat(10)]
345+
[Trait("Category", "sync")]
347346
public async Task Test400_Sync(int repeatCount)
348347
{
349348
var cut = RenderComponent<CounterComponentDynamic>();

‎tests/bunit.web.tests/EventDispatchExtensions/InputEventDispatchExtensionsTest.cs‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,10 @@ public class InputEventDispatchExtensionsTest : EventDispatchExtensionsTest<Chan
1111

1212
protected override string ElementName => "input";
1313

14+
public InputEventDispatchExtensionsTest(ITestOutputHelper outputHelper) : base(outputHelper)
15+
{
16+
}
17+
1418
[Theory(DisplayName = "Input events are raised correctly through helpers")]
1519
[MemberData(nameof(Helpers))]
1620
public void CanRaiseEvents(MethodInfo helper)

0 commit comments

Comments
 (0)