Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Increase logs and delays in CanLaunchPhotinoWebViewAndClickButton #54608

Merged
merged 1 commit into from
Apr 2, 2024
Merged

Increase logs and delays in CanLaunchPhotinoWebViewAndClickButton #54608

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
52 changes: 28 additions & 24 deletions src/Components/WebView/test/E2ETest/BasicBlazorHybridTest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,21 +18,21 @@ public void Run()
// Note: This test produces *a lot* of debug output to aid when debugging failures. The only output
// that is necessary for the functioning of this test is the "Test passed" at the end of this method.

Console.WriteLine($"Current directory: {Environment.CurrentDirectory}");
Console.WriteLine($"Current assembly: {typeof(Program).Assembly.Location}");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Current directory: {Environment.CurrentDirectory}");
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All these DateTime.Now's are so that each line within the log has the actual time it was generated. Otherwise all the lines get written out to the xUnit log at the same time and thus all have the same timestamp, which isn't useful if you're trying to see how long it took between lines.

Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Current assembly: {typeof(Program).Assembly.Location}");
var thisProgramDir = Path.GetDirectoryName(typeof(Program).Assembly.Location);

// Add correct runtime sub-folder to PATH to ensure native files are discovered (this is supposed to happen automatically, but somehow it doesn't...)
var newNativePath = Path.Combine(thisProgramDir, "runtimes", RuntimeInformation.RuntimeIdentifier, "native");
Console.WriteLine($"Adding new native path: {newNativePath}");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Adding new native path: {newNativePath}");
Environment.SetEnvironmentVariable("PATH", newNativePath + ";" + Environment.GetEnvironmentVariable("PATH"));
Console.WriteLine($"New PATH env var: {Environment.GetEnvironmentVariable("PATH")}");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] New PATH env var: {Environment.GetEnvironmentVariable("PATH")}");

var thisAppFiles = Directory.GetFiles(thisProgramDir, "*", SearchOption.AllDirectories).ToArray();
Console.WriteLine($"Found {thisAppFiles.Length} files in this app:");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Found {thisAppFiles.Length} files in this app:");
foreach (var file in thisAppFiles)
{
Console.WriteLine($"\t{file}");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] \t{file}");
}

var hostPage = "wwwroot/webviewtesthost.html";
Expand All @@ -41,7 +41,7 @@ public void Run()
serviceCollection.AddBlazorWebView();
serviceCollection.AddSingleton<HttpClient>();

Console.WriteLine($"Creating BlazorWindow...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Creating BlazorWindow...");
BlazorWindow mainWindow = null;
try
{
Expand All @@ -53,27 +53,27 @@ public void Run()
}
catch (Exception ex)
{
Console.WriteLine($"Exception {ex.GetType().FullName} while creating window: {ex.Message}");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Exception {ex.GetType().FullName} while creating window: {ex.Message}");
Console.WriteLine(ex.StackTrace);
}

Console.WriteLine($"Hooking exception handler...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Hooking exception handler...");
AppDomain.CurrentDomain.UnhandledException += (sender, error) =>
{
Console.Write(
"Fatal exception" + Environment.NewLine +
error.ExceptionObject.ToString() + Environment.NewLine);
};

Console.WriteLine($"Setting up root components...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Setting up root components...");
mainWindow.RootComponents.Add<Pages.TestPage>("root");

Console.WriteLine($"Running window...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Running window...");

const string NewControlDivValueMessage = "wvt:NewControlDivValue";
var isWebViewReady = false;

Console.WriteLine($"RegisterWebMessageReceivedHandler...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] RegisterWebMessageReceivedHandler...");
mainWindow.PhotinoWindow.RegisterWebMessageReceivedHandler((s, msg) =>
{
if (!msg.StartsWith("__bwv:", StringComparison.Ordinal))
Expand All @@ -90,29 +90,33 @@ public void Run()
});
var testPassed = false;

Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Attaching WindowCreated handler...");
mainWindow.PhotinoWindow.WindowCreated += (s, e) =>
{
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] In WindowCreated event...");
Task.Run(async () =>
{
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] In async test task...");

try
{
// This is the actual test logic here (wait for WebView, click button, verify updates, etc.)

// 1. Wait for WebView ready
Console.WriteLine($"Waiting for WebView ready...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Waiting for WebView ready...");
var isWebViewReadyRetriesLeft = 20;
while (!isWebViewReady)
{
Console.WriteLine($"WebView not ready yet, waiting 1sec...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] WebView not ready yet, waiting 1sec...");
await Task.Delay(1000);
isWebViewReadyRetriesLeft--;
if (isWebViewReadyRetriesLeft == 0)
{
Console.WriteLine($"WebView never became ready, failing the test...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] WebView never became ready, failing the test...");
return;
}
}
Console.WriteLine($"WebView is ready!");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] WebView is ready!");

// 2. Check TestPage starting state
if (!await WaitForControlDiv(mainWindow.PhotinoWindow, controlValueToWaitFor: "0"))
Expand All @@ -130,7 +134,7 @@ public void Run()
}

// 5. If we get here, it all worked!
Console.WriteLine($"All tests passed!");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] All tests passed!");
testPassed = true;
}
catch (Exception ex)
Expand All @@ -153,16 +157,16 @@ public void Run()
}
catch (Exception ex)
{
Console.WriteLine($"Exception while running window: {ex}");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Exception while running window: {ex}");
}

// This line is what's required for the test to be considered as passed. The xUnit test in WebViewManagerE2ETests checks
// that this reports success and that decides if the test is pass/fail.
Console.WriteLine($"Test passed? {testPassed}");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Test passed? {testPassed}");
}

const int MaxWaitTimes = 30;
const int WaitTimeInMS = 250;
const int WaitTimeInMS = 1000;
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Increase delay time for this retry to hopefully help improve success rate.


public async Task<bool> WaitForControlDiv(PhotinoWindow photinoWindow, string controlValueToWaitFor)
{
Expand All @@ -172,20 +176,20 @@ public async Task<bool> WaitForControlDiv(PhotinoWindow photinoWindow, string co
// Tell WebView to report the current controlDiv value (this is inside the loop because
// it's possible for this to execute before the WebView has finished processing previous
// C#-generated events, such as WebView button clicks).
Console.WriteLine($"Asking WebView for current controlDiv value...");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Asking WebView for current controlDiv value...");
photinoWindow.SendWebMessage($"wvt:GetControlDivValue");

// And wait for the value to appear
if (_latestControlDivValue == controlValueToWaitFor)
{
Console.WriteLine($"WebView reported the expected controlDiv value of {controlValueToWaitFor}!");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] WebView reported the expected controlDiv value of {controlValueToWaitFor}!");
return true;
}
Console.WriteLine($"Waiting for controlDiv to have value '{controlValueToWaitFor}', but it's still '{_latestControlDivValue}', so waiting {WaitTimeInMS}ms.");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Waiting for controlDiv to have value '{controlValueToWaitFor}', but it's still '{_latestControlDivValue}', so waiting {WaitTimeInMS}ms.");
await Task.Delay(WaitTimeInMS);
}

Console.WriteLine($"Waited {MaxWaitTimes * WaitTimeInMS}ms but couldn't get controlDiv to have value '{controlValueToWaitFor}' (last value is '{_latestControlDivValue}').");
Console.WriteLine($"[{DateTime.Now.ToLongTimeString()}] Waited {MaxWaitTimes * WaitTimeInMS}ms but couldn't get controlDiv to have value '{controlValueToWaitFor}' (last value is '{_latestControlDivValue}').");
return false;
}
}
7 changes: 5 additions & 2 deletions src/Components/WebView/test/E2ETest/WebViewManagerE2ETests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,10 +3,11 @@

using System.Diagnostics;
using Microsoft.AspNetCore.Testing;
using Xunit.Abstractions;

namespace Microsoft.AspNetCore.Components.WebViewE2E.Test;

public class WebViewManagerE2ETests
public class WebViewManagerE2ETests(ITestOutputHelper output)
{
// Skips:
// - Ubuntu is skipped due to this error:
Expand Down Expand Up @@ -39,7 +40,9 @@ public async Task CanLaunchPhotinoWebViewAndClickButton()

var testProgramOutput = photinoProcess.StandardOutput.ReadToEnd();

await photinoProcess.WaitForExitAsync().TimeoutAfter(TimeSpan.FromSeconds(30));
await photinoProcess.WaitForExitAsync().TimeoutAfter(TimeSpan.FromSeconds(60));

output.WriteLine(testProgramOutput);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Always log the test output even on successful runs to help compare successful runs to failed runs (in case it turns out to be a machine slowness issue).


// The test app reports its own results by calling Console.WriteLine(), so here we only need to verify that
// the test internally believes it passed (and we trust it!).
Expand Down
Loading