Adds a rendering performance test (#24762)

src/Controls/tests/TestCases.HostApp/Issues/RenderingPerformance.xaml

@@ -0,0 +1,41 @@
+<?xml version="1.0" encoding="utf-8" ?>
+<ContentPage xmlns="http://schemas.microsoft.com/dotnet/2021/maui"
+             xmlns:x="http://schemas.microsoft.com/winfx/2009/xaml"
+             xmlns:issues="clr-namespace:Maui.Controls.Sample.Issues"
+             x:Class="Maui.Controls.Sample.Issues.RenderingPerformance"
+             Title="RenderingPerformance">
+
+    <Grid Padding="24" RowDefinitions="Auto,Auto,*" RowSpacing="8">
+      <Button x:Name="StartButton" Clicked="ButtonClicked" Text="Start" AutomationId="StartButton" />
+      <Label Grid.Row="1" Text="Do not press 'Start' more than once, just wait." />
+
+      <ScrollView Grid.Row="2">
+        <ContentView>
+          <VerticalStackLayout x:Name="BindableContainer" BindableLayout.ItemsSource="{Binding Models}">
+            <BindableLayout.ItemTemplate>
+              <DataTemplate>
+                <Border Margin="0,16" Padding="8" StrokeShape="RoundRectangle 8" Background="LightBlue">
+                  <Grid RowDefinitions="Auto,Auto,Auto">
+                    <Label Text="{Binding Header}" />
+                    <Label Text="{Binding Content}" Grid.Row="1" />
+                    <VerticalStackLayout Grid.Row="2" BindableLayout.ItemsSource="{Binding SubModels}" Margin="16,0">
+                      <BindableLayout.ItemTemplate>
+                        <DataTemplate>
+                          <ContentView>
+                            <VerticalStackLayout Margin="0,8">
+                              <Label Text="{Binding Header}" />
+                              <issues:MeasuredLabel IsMeasured="{Binding IsMeasured}" Text="{Binding Content}" />
+                            </VerticalStackLayout>
+                          </ContentView>
+                        </DataTemplate>
+                      </BindableLayout.ItemTemplate>
+                    </VerticalStackLayout>
+                  </Grid>
+                </Border>
+              </DataTemplate>
+            </BindableLayout.ItemTemplate>
+          </VerticalStackLayout>
+        </ContentView>
+      </ScrollView>
+    </Grid>
+</ContentPage>

src/Controls/tests/TestCases.HostApp/Issues/RenderingPerformance.xaml.cs

@@ -0,0 +1,220 @@
+using System;
+using System.Collections.ObjectModel;
+using System.Diagnostics;
+using System.Globalization;
+using Microsoft.Maui;
+using Microsoft.Maui.Controls;
+using Microsoft.Maui.Controls.Xaml;
+using ILayout = Microsoft.Maui.ILayout;
+
+namespace Maui.Controls.Sample.Issues;
+
+public class MeasuredLabel : Label
+{
+	private static readonly TimeSpan ArrangedThreshold = TimeSpan.FromSeconds(1);
+	public static readonly BindableProperty IsMeasuredProperty = BindableProperty.Create(nameof(IsMeasured), typeof(bool), typeof(MeasuredLabel), false);
+
+	public bool IsMeasured
+	{
+		get => (bool)GetValue(IsMeasuredProperty);
+		set => SetValue(IsMeasuredProperty, value);
+	}
+
+	public long? LastArrangedTicks { get; set; }
+
+	public long? GetArrangeTicks() {
+		if (LastArrangedTicks is { } ticks)
+		{
+			var elapsed = Stopwatch.GetElapsedTime(ticks);
+			if (elapsed > ArrangedThreshold)
+			{
+				return ticks;
+			}
+		}
+
+		return null;
+	}
+}
+
+public static class RenderingPerformanceExtensions
+{
+	public static MauiAppBuilder RenderingPerformanceAddMappers(this MauiAppBuilder builder)
+	{
+		builder.ConfigureMauiHandlers(handlers => 
+		{
+			Microsoft.Maui.Handlers.LabelHandler.CommandMapper.AppendToMapping(nameof(IView.Frame), (handler, view, arg) =>
+			{
+				if (view is MeasuredLabel { IsMeasured: true } measuredLabel)
+				{
+					measuredLabel.LastArrangedTicks = Stopwatch.GetTimestamp();
+				}
+			});
+		});
+
+		return builder;
+	}
+}
+
+[XamlCompilation(XamlCompilationOptions.Compile)]
+[Issue(IssueTracker.None, 0, "Rendering performance", PlatformAffected.All)]
+public partial class RenderingPerformance : ContentPage
+{
+	bool _firstRun = true;
+
+	public List<ViewModelStub> Models { get; set; }
+
+	public RenderingPerformance()
+	{
+		Models = GenerateMeasuredItem();
+		BindingContext = this;
+		InitializeComponent();
+	}
+
+	private async void ButtonClicked(object sender, EventArgs e)
+	{
+		var capturedTimes = new List<int[]>();
+
+		// Generate view models so that only the last NestedViewModelStub of the last ViewModelStub is measured 
+		// First time we generate 40 * 10 + 1 = 401 items
+		// This causes the creation of (40 * 5) + (40 * 10 * 4) + (1 * 5) + (1 * 4) = ~1800 platform views
+		var test1Models = GenerateItems(40, "First");
+		// Second time we generate 20 * 10 + 1 = 201 items
+		// This causes (20 * 5) + (20 * 10 * 4) = ~900 binding context changes
+		// and other ~900 platform views removals
+		var test2Models = GenerateItems(20, "Second");
+		// Third time we manually clear the BindableContainer and reset the models to the initial state (1 measured item) 
+		var resetModel = GenerateMeasuredItem();
+
+		// This enables us to measure the time it takes to:
+		// - Create platform views
+		// - Bind the new view models
+		// - Remove platform views
+		// - Clear platform views
+
+		// Views include frequently used components like `ContentView` (legacy layout), `Border`, `VerticalStackLayout`, `Grid`, `Label`.
+		// Measurement happens by tracking IView.Frame mapping which happens right after the platform has arranged the view in the container view.
+
+		// Clear the first measure (happened while rendering the page for the first time)
+		if (_firstRun)
+		{
+			_firstRun = false;
+			await GetArrangeTicksAsync();
+		}
+
+		for (var i = 0; i < 5; i++)
+		{
+			await Task.Delay(200);
+
+			Models = test1Models;
+			var startTicks = Stopwatch.GetTimestamp();
+			OnPropertyChanged(nameof(Models));
+			var endTicks = await Task.Run(GetArrangeTicksAsync);
+			var t1 = (int)Stopwatch.GetElapsedTime(startTicks, endTicks).TotalMilliseconds;
+
+			await Task.Delay(200);
+
+			Models = test2Models;
+			startTicks = Stopwatch.GetTimestamp();
+			OnPropertyChanged(nameof(Models));
+			endTicks = await Task.Run(GetArrangeTicksAsync);
+			var t2 = (int)Stopwatch.GetElapsedTime(startTicks, endTicks).TotalMilliseconds;
+
+			await Task.Delay(200);
+
+			startTicks = Stopwatch.GetTimestamp();
+			BindableContainer.Clear();
+			Models = resetModel;
+			OnPropertyChanged(nameof(Models));
+			endTicks = await Task.Run(GetArrangeTicksAsync);
+			var t3 = (int)Stopwatch.GetElapsedTime(startTicks, endTicks).TotalMilliseconds;
+
+			capturedTimes.Add([t1, t2, t3]);
+		}
+
+		var avg1 = (int)capturedTimes.Average(t => t[0]);
+		var avg2 = (int)capturedTimes.Average(t => t[1]);
+		var avg3 = (int)capturedTimes.Average(t => t[2]);
+		StartButton.Text = $"{avg1},{avg2},{avg3}";
+	}
+
+	/// <summary>
+	/// Traverse the visual tree to find the last MeasuredLabel and return its arrange ticks when found
+	/// </summary>
+	/// <returns></returns>
+	async Task<long> GetArrangeTicksAsync()
+	{
+		while (true)
+		{
+			await Task.Delay(100);
+			IView view = BindableContainer;
+			while (true)
+			{
+				if (view is ILayout { Count: > 0 } layout)
+				{
+					view = layout[^1];
+				}
+				else if (view is IContentView contentView)
+				{
+					view = (IView)contentView.Content;
+				}
+				else
+				{
+					break;
+				}
+			}
+
+			if (view is MeasuredLabel measuredLabel && measuredLabel.GetArrangeTicks() is { } arrangeTicks)
+			{
+				measuredLabel.LastArrangedTicks = null;
+				return arrangeTicks;
+			}
+		}
+	}
+
+	static List<ViewModelStub> GenerateItems(int count, string prefix)
+	{
+		return
+		[
+			..Enumerable.Range(0, count).Select(i => new ViewModelStub
+			{
+				Content = $"{prefix} Content {i}",
+				Header = $"Header {i}",
+				SubModels = Enumerable.Range(0, 10).Select(j => new NestedViewModelStub
+				{
+					Content = $"{prefix} SubContent {j}", Header = $"{prefix} SubHeader {j}"
+				}).ToArray()
+			}),
+			..GenerateMeasuredItem()
+		];
+	}
+
+	static List<ViewModelStub> GenerateMeasuredItem()
+	{
+		return
+		[
+			new ViewModelStub
+			{
+				Content = "Measured Content",
+				Header = "Measured Header",
+				SubModels =
+				[
+					new NestedViewModelStub { Content = "Measured SubContent", Header = "Measured SubHeader", IsMeasured = true }
+				]
+			}
+		];
+	}
+
+	public class ViewModelStub
+	{
+		public string Header { get; set; }
+		public string Content { get; set; }
+		public NestedViewModelStub[] SubModels { get; set; }
+	}
+
+	public class NestedViewModelStub
+	{
+		public string Header { get; set; }
+		public string Content { get; set; }
+		public bool IsMeasured { get; set; }
+	}
+}

src/Controls/tests/TestCases.HostApp/MauiProgram.cs

@@ -23,6 +23,7 @@ public static MauiApp CreateMauiApp()
 					fonts.AddFont("FontAwesome.ttf", "FA");
 					fonts.AddFont("ionicons.ttf", "Ion");
 				})
+				.RenderingPerformanceAddMappers()
 				.Issue21109AddMappers()
 				.Issue18720AddMappers()
 				.Issue18720EditorAddMappers()

src/Controls/tests/TestCases.Shared.Tests/Tests/Issues/RenderingPerformance.cs

@@ -0,0 +1,37 @@
+using NUnit.Framework;
+using NUnit.Framework.Legacy;
+using UITest.Appium;
+using UITest.Core;
+
+namespace Microsoft.Maui.TestCases.Tests.Issues
+{
+	public class RenderingPerformance : _IssuesUITest
+	{
+		public RenderingPerformance(TestDevice device) : base(device) { }
+
+		public override string Issue => "Rendering performance";
+
+		[Test]
+		[Category(UITestCategories.Performance)]
+		public async Task RenderingPerformanceRun()
+		{
+			const string automationId = "StartButton";
+
+			var button = App.WaitForElement(automationId);
+			App.Tap(automationId);
+
+			var timeout = TimeSpan.FromMinutes(5);  // MACCATALYST takes a long time to run this test
+			App.WaitForTextToBePresentInElement(automationId, ",", timeout);
+
+			var times = button.GetText()?.Split(',') ?? throw new ArgumentNullException("StartButton text is null");
+
+			var logMessage = @$"RenderingPerformance: [{times[0]}, {times[1]}, {times[2]}]";
+			TestContext.WriteLine(logMessage);
+
+			// Write the log to a file and attach it to the test results for ADO
+			var logFile = Path.Combine(Path.GetTempPath(), "RenderingPerformance.log");
+			await File.WriteAllTextAsync(logFile, logMessage);
+			TestContext.AddTestAttachment(logFile, "RenderingPerformance.log");
+		}
+	}
+}

src/TestUtils/src/UITest.Appium/HelperExtensions.cs

@@ -401,11 +401,10 @@ public static void WaitForNoElement(
 			Wait(query, i => i is null, timeoutMessage, timeout, retryFrequency);
 		}
 
-		public static bool WaitForTextToBePresentInElement(this IApp app, string automationId, string text)
+		public static bool WaitForTextToBePresentInElement(this IApp app, string automationId, string text, TimeSpan? timeout = null)
 		{
-			TimeSpan timeout = DefaultTimeout;
+			timeout ??= DefaultTimeout;
 			TimeSpan retryFrequency = TimeSpan.FromMilliseconds(500);
-			string timeoutMessage = $"Timed out on {nameof(WaitForTextToBePresentInElement)}.";
 
 			DateTime start = DateTime.Now;
 
@@ -418,9 +417,9 @@ public static bool WaitForTextToBePresentInElement(this IApp app, string automat
 				}
 
 				long elapsed = DateTime.Now.Subtract(start).Ticks;
-				if (elapsed >= timeout.Ticks)
+				if (elapsed >= timeout.Value.Ticks)
 				{
-					Debug.WriteLine($">>>>> {elapsed} ticks elapsed, timeout value is {timeout.Ticks}");
+					Debug.WriteLine($">>>>> {elapsed} ticks elapsed, timeout value is {timeout.Value.Ticks}");
 
 					return false;
 				}