Fix TestBuilderTests flakyness #5216

sebastienros · 2024-08-07T19:49:38Z

Fixes

Aspire.Hosting.Testing.Tests.TestingBuilderTests.HttpClientGetTest(genericEntryPoint: True) [FAIL]
Aspire.Hosting.Testing.Tests.TestingBuilderTests.HttpClientGetTest(genericEntryPoint: False) [FAIL]
Aspire.Hosting.Testing.Tests.TestingBuilderTests.SelectsFirstLaunchProfile(genericEntryPoint: True) [FAIL]
Aspire.Hosting.Testing.Tests.TestingBuilderTests.SelectsFirstLaunchProfile(genericEntryPoint: False) [FAIL]
Aspire.Hosting.Testing.Tests.TestingFactoryTests.HttpClientGetTest [FAIL]

Fixed the tests on local Linux box. Was failing consistently before.

Microsoft Reviewers: Open in CodeFlow

tests/Aspire.Hosting.Tests/Utils/LoggerNotificationExtensions.cs

sebastienros · 2024-08-07T20:25:34Z

NB: this is very similar to what ResourceLoggerForwarderService is doing but ti wait for specific events instead of just forwarding it to logs.

radical · 2024-08-07T21:59:01Z

This should fix #4650 .

radical · 2024-08-07T22:00:25Z

This should fix #4650 .

.. which should allow re-enabling the corresponding tests in TestingFactoryTests.

radical

LGTM 👍

eerhardt · 2024-08-08T14:48:50Z

tests/Aspire.Hosting.Tests/Utils/LoggerNotificationExtensions.cs

+            await foreach (var resourceEvent in resourceNotificationService.WatchAsync(cancellationToken).ConfigureAwait(false))
+            {
+                if (resource != null && resourceEvent.Resource != resource)
+                {
+                    continue;
+                }
+
+                var resourceId = resourceEvent.ResourceId;
+
+                if (loggingResourceIds.Add(resourceId))
+                {
+                    // Start watching the logs for this resource ID
+                    logWatchTasks.Add(WatchResourceLogs(tcs, resourceId, logTexts, resourceLoggerService, cancellationToken));
+                }
+            }


How does this loop ever stop? Only once the application stops?

eerhardt · 2024-08-08T14:53:35Z

tests/Aspire.Hosting.Testing.Tests/TestingFactoryTests.cs

@@ -47,6 +48,9 @@ public async Task HttpClientGetTest()
        var rns = _app.Services.GetRequiredService<ResourceNotificationService>();
        await rns.WaitForResourceAsync("mywebapp1").WaitAsync(TimeSpan.FromSeconds(60));

+        // Wait for the application to be ready
+        await _app.WaitForTextAsync("Application started.").WaitAsync(TimeSpan.FromMinutes(1));


We are already await rns.WaitForResourceAsync("mywebapp1") above. Why is this wait needed?

If the existing code isn't good enough, then i think we might need to change our test template code as well, because the previous code is basically what the template spits out:

aspire/src/Aspire.ProjectTemplates/templates/aspire-xunit/IntegrationTest1.cs

Lines 25 to 32 in 024b48b

// await using var app = await appHost.BuildAsync();

// var resourceNotificationService = app.Services.GetRequiredService<ResourceNotificationService>();

// await app.StartAsync();

// // Act

// var httpClient = app.CreateHttpClient("webfrontend");

// await resourceNotificationService.WaitForResourceAsync("webfrontend", KnownResourceStates.Running).WaitAsync(TimeSpan.FromSeconds(30));

// var response = await httpClient.GetAsync("/");

cc @DamianEdwards @ReubenBond

I assume WaitForResourceAsync doesn't account for when the service can actually serve requests. I dumped the logs for this test and added markers before/after each call:

2024-08-08T18:39:12.3897554Z WaitForResourceAsync - Start 2024-08-08T18:39:13.5023642Z WaitForResourceAsync - Stopped 2024-08-08T18:39:13.5024903Z WaitForTextAsync - Start 2024-08-08T18:39:14.3305581Z WaitForTextAsync - Stopped

So quite some delay between WaitForResourceAsync and the application is ready.

Full logs:

info: Aspire.Hosting.DistributedApplication[0] Aspire version: 8.1.1-dev info: Aspire.Hosting.DistributedApplication[0] Distributed application starting. info: Aspire.Hosting.DistributedApplication[0] Application host directory is: D:\aspire\tests\TestingAppHost1\TestingAppHost1.AppHost info: Aspire.Hosting.DistributedApplication[0] Distributed application started. Press Ctrl+C to shut down. info: Aspire.Hosting.Testing.Tests.TestingFactoryTests[0] 2024-08-08T18:39:12.3897554Z WaitForResourceAsync - Start info: TestingAppHost1.AppHost.Resources.redis1[0] 1: 2024-08-08T18:39:12.504Z f6a9967856a8e04bcc5bac50d9773fd829b7efc3b0c40501a3bf87a63ae76c01 info: TestingAppHost1.AppHost.Resources.postgres1[0] 1: 2024-08-08T18:39:12.508Z 3340cd55a0075dabf1fa27fecbbac6550efdd35d16e358cc5506da329512e0ec fail: Aspire.Hosting.Dcp.dcpctrl.ExecutableReconciler[0] could not create Endpoint object {"Executable": {"name":"myworker1-76788608-hs44so590k"}, "Reconciliation": 7, "ServiceName": "myworker1-76788608", "Workload": "/myworker1-76788608-hs44so590k", "error": "service-producer annotation is invalid: missing information about the port to expose the service"} info: TestingAppHost1.AppHost.Resources.myworker1[0] 1: 2024-08-08T11:39:12.7923490 info: Microsoft.Hosting.Lifetime[0] info: TestingAppHost1.AppHost.Resources.myworker1[0] 2: Application started. Press Ctrl+C to shut down. info: TestingAppHost1.AppHost.Resources.myworker1[0] 3: 2024-08-08T11:39:12.8009449 info: Microsoft.Hosting.Lifetime[0] info: TestingAppHost1.AppHost.Resources.myworker1[0] 4: Hosting environment: Production info: TestingAppHost1.AppHost.Resources.myworker1[0] 5: 2024-08-08T11:39:12.8010763 info: Microsoft.Hosting.Lifetime[0] info: TestingAppHost1.AppHost.Resources.myworker1[0] 6: Content root path: D:\aspire\artifacts\bin\TestingAppHost1.MyWorker\Debug\net8.0 info: Aspire.Hosting.Testing.Tests.TestingFactoryTests[0] 2024-08-08T18:39:13.5023642Z WaitForResourceAsync - Stopped info: Aspire.Hosting.Testing.Tests.TestingFactoryTests[0] 2024-08-08T18:39:13.5024903Z WaitForTextAsync - Start info: TestingAppHost1.AppHost.Resources.redis1[0] 2: info: TestingAppHost1.AppHost.Resources.redis1[0] 3: 2024-08-08T18:39:13.369Z f6a9967856a8e04bcc5bac50d9773fd829b7efc3b0c40501a3bf87a63ae76c01 info: TestingAppHost1.AppHost.Resources.postgres1[0] 2: info: TestingAppHost1.AppHost.Resources.postgres1[0] 3: 2024-08-08T18:39:13.392Z 3340cd55a0075dabf1fa27fecbbac6550efdd35d16e358cc5506da329512e0ec fail: Aspire.Hosting.Dcp.dcpctrl.ExecutableReconciler[0] could not create Endpoint object {"Executable": {"name":"myworker1-76788608-hs44so590k"}, "Reconciliation": 15, "ServiceName": "myworker1-76788608", "Workload": "/myworker1-76788608-hs44so590k", "error": "service-producer annotation is invalid: missing information about the port to expose the service"} info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 1: 2024-08-08T11:39:13.9218060 info: Microsoft.Hosting.Lifetime[14] info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 2: Now listening on: https://localhost:7097 info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 3: 2024-08-08T11:39:13.9288476 info: Microsoft.Hosting.Lifetime[14] info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 4: Now listening on: http://localhost:5150 info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 5: 2024-08-08T11:39:13.9892275 info: Microsoft.Hosting.Lifetime[0] info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 6: Application started. Press Ctrl+C to shut down. info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 7: 2024-08-08T11:39:13.9903828 info: Microsoft.Hosting.Lifetime[0] info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 8: Hosting environment: Development info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 9: 2024-08-08T11:39:13.9904583 info: Microsoft.Hosting.Lifetime[0] info: TestingAppHost1.AppHost.Resources.mywebapp1[0] 10: Content root path: D:\aspire\tests\TestingAppHost1\TestingAppHost1.MyWebApp info: Aspire.Hosting.Testing.Tests.TestingFactoryTests[0] 2024-08-08T18:39:14.3305581Z WaitForTextAsync - Stopped

My concern is how does the tests in our template work today without this? Do we hve this flakiness issue in them?

Fix TestBuilderTests flakyness

5de55a2

sebastienros requested review from mitchdenny and ReubenBond as code owners August 7, 2024 19:49

ghost added the area-integrations Issues pertaining to Aspire Integrations packages label Aug 7, 2024

sebastienros requested a review from radical August 7, 2024 20:05

radical reviewed Aug 7, 2024

View reviewed changes

tests/Aspire.Hosting.Tests/Utils/LoggerNotificationExtensions.cs Outdated Show resolved Hide resolved

radical reviewed Aug 7, 2024

View reviewed changes

tests/Aspire.Hosting.Tests/Utils/LoggerNotificationExtensions.cs Show resolved Hide resolved

radical reviewed Aug 7, 2024

View reviewed changes

tests/Aspire.Hosting.Tests/Utils/LoggerNotificationExtensions.cs Outdated Show resolved Hide resolved

PR feedback

e718020

radical approved these changes Aug 7, 2024

View reviewed changes

sebastienros merged commit 024b48b into main Aug 8, 2024
11 checks passed

sebastienros deleted the sebros/flakyness branch August 8, 2024 04:16

eerhardt reviewed Aug 8, 2024

View reviewed changes

github-actions bot locked and limited conversation to collaborators Sep 9, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Fix TestBuilderTests flakyness #5216

Fix TestBuilderTests flakyness #5216

Uh oh!

sebastienros commented Aug 7, 2024 •

edited

Loading

Uh oh!

Uh oh!

Uh oh!

Uh oh!

sebastienros commented Aug 7, 2024

Uh oh!

radical commented Aug 7, 2024

Uh oh!

radical commented Aug 7, 2024

Uh oh!

radical left a comment

Uh oh!

Uh oh!

eerhardt Aug 8, 2024

Uh oh!

eerhardt Aug 8, 2024

Uh oh!

sebastienros Aug 8, 2024 •

edited

Loading

Uh oh!

eerhardt Aug 8, 2024

Uh oh!

Uh oh!

	// await using var app = await appHost.BuildAsync();
	// var resourceNotificationService = app.Services.GetRequiredService<ResourceNotificationService>();
	// await app.StartAsync();

	// // Act
	// var httpClient = app.CreateHttpClient("webfrontend");
	// await resourceNotificationService.WaitForResourceAsync("webfrontend", KnownResourceStates.Running).WaitAsync(TimeSpan.FromSeconds(30));
	// var response = await httpClient.GetAsync("/");

Fix TestBuilderTests flakyness #5216

Fix TestBuilderTests flakyness #5216

Uh oh!

Conversation

sebastienros commented Aug 7, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Microsoft Reviewers: Open in CodeFlow

Uh oh!

Uh oh!

Uh oh!

Uh oh!

sebastienros commented Aug 7, 2024

Uh oh!

radical commented Aug 7, 2024

Uh oh!

radical commented Aug 7, 2024

Uh oh!

radical left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

eerhardt Aug 8, 2024

Choose a reason for hiding this comment

Uh oh!

eerhardt Aug 8, 2024

Choose a reason for hiding this comment

Uh oh!

sebastienros Aug 8, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

eerhardt Aug 8, 2024

Choose a reason for hiding this comment

Uh oh!

Uh oh!

sebastienros commented Aug 7, 2024 •

edited

Loading

sebastienros Aug 8, 2024 •

edited

Loading