Test Failure: UseStartupFactoryWorks

[JunTaoLuo]

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1017405&view=ms.vss-test-web.build-test-results-tab&runId=31669222&resultId=101504&paneView=debug

Log:

Assert.Equal() Failure
↓ (pos 1)
Expected: 0123456789abcdef
Actual:   0000000000000000
↑ (pos 1)
   at Microsoft.AspNetCore.Hosting.Tests.HostingApplicationDiagnosticsTests.<>c.<ActivityListenersAreCalled>b__17_2(Activity activity) in /_/src/Hosting/Hosting/test/HostingApplicationDiagnosticsTests.cs:line 506
   at System.Diagnostics.ActivitySource.<>c.<NotifyActivityStart>b__24_0(ActivityListener listener, Object obj)
   at System.Diagnostics.SynchronizedList`1.EnumWithAction(Action`2 action, Object arg)
   at System.Diagnostics.ActivitySource.NotifyActivityStart(Activity activity)
   at System.Diagnostics.Activity.Start()
   at Microsoft.AspNetCore.Hosting.HostingApplicationDiagnostics.StartActivity(HttpContext httpContext, Boolean loggingEnabled, Boolean diagnosticListenerActivityCreationEnabled, Boolean& hasDiagnosticListener) in /_/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs:line 309
   at Microsoft.AspNetCore.Hosting.HostingApplication.CreateContext(IFeatureCollection contextFeatures) in /_/src/Hosting/Hosting/src/Internal/HostingApplication.cs:line 80
   at Microsoft.AspNetCore.Hosting.WebHostBuilderTests.TestServer.<>c__DisplayClass8_0`1.<<StartAsync>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Hosting.WebHostBuilderTests.AssertResponseContains(RequestDelegate app, String expectedText) in /_/src/Hosting/Hosting/test/WebHostBuilderTests.cs:line 1503
   at Microsoft.AspNetCore.Hosting.WebHostBuilderTests.UseStartupFactoryWorks(IWebHostBuilder builder) in /_/src/Hosting/Hosting/test/WebHostBuilderTests.cs:line 132
--- End of stack trace from previous location ---

[ghost]

Thanks for contacting us.
We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We will evaluate the request when we are planning the work for the next milestone. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

[Tratcher]

@shirhatti?

[shirhatti]

The test that's been quarantined is something completely different from the failing test from the stack trace.

I'm so confused on what's going here 😕

[JunTaoLuo]

Hmm the stack trace has parts of both tests so maybe some state is being shared between the two?

at Microsoft.AspNetCore.Hosting.Tests.HostingApplicationDiagnosticsTests.<>c.<ActivityListenersAreCalled>b__17_2(Activity activity) in /_/src/Hosting/Hosting/test/HostingApplicationDiagnosticsTests.cs:line 506

and

at Microsoft.AspNetCore.Hosting.WebHostBuilderTests.UseStartupFactoryWorks(IWebHostBuilder builder) in /_/src/Hosting/Hosting/test/WebHostBuilderTests.cs:line 132

This is a strange one for sure.

[shirhatti]

Do these tests execute concurrently? If so, that's a plausible explanation. ActivityListeners/DiagnosticListener are global. If they execute concurrently it makes sense that an ActivityListener callback is firing elsewhere.

The fix here would be to add an testing only ctor to HostingApplicationDiagnostics that allow me specify a prefix to ensure Activity names are globally unique. Though I remain somewhat surprised that this hasn't ever happened before.

Also assuming my hypothesis is right, quarantining doesn't do much since as long as WebHostBuilderTests and HostingApplicationDiagnosticsTests run concurrently any of those tests can fail

[shirhatti]

Also @tarekgh if you have any suggestions here. Do you have any similar issues with tests in the runtime repo failing because they use the same ActivityName?

[tarekgh]

@shirhatti in our runtime repo, we always execute the tests in isolation using the remote executor. Here is some example https://github.com/dotnet/runtime/blob/ab9d49ce146c8f19763b6469e2db7d815c7d9de5/src/libraries/System.Diagnostics.DiagnosticSource/tests/ActivitySourceTests.cs#L21

The other idea you can do, use Boolean variable to ensure it will be set to true inside the listener at some point. something like:

        [Fact]
        public void ActivityListenersAreCalled()
        {
            bool encountered = false;
            var hostingApplication = CreateApplication(out var features);
            using var listener = new ActivityListener
            {
                ShouldListenTo = activitySource => true,
                Sample = (ref ActivityCreationOptions<ActivityContext> _) => ActivitySamplingResult.AllData,
                ActivityStarted = activity =>
                {
                    if ("0123456789abcdef" == activity.ParentSpanId.ToHexString())
                    {
                        encountered = true;
                    }
                }
            };

            ActivitySource.AddActivityListener(listener);

            features.Set<IHttpRequestFeature>(new HttpRequestFeature()
            {
                Headers = new HeaderDictionary()
                {
                    {"traceparent", "00-0123456789abcdef0123456789abcdef-0123456789abcdef-01"},
                    {"tracestate", "TraceState1"},
                    {"baggage", "Key1=value1, Key2=value2"}
                }
            });
            hostingApplication.CreateContext(features);

            Assert.True(encountered);
        }

[shirhatti]

All tests in HostingApplicationDiagnosticsTests rely on global state in the process and are susceptible to side effects from any other tests in which HostingApplication.CreateContext may be called (which is a lot of tests!). All these tests need to be vetted for this failure mode. Tarek's suggestion would probably suffice to fix most of these tests.

[halter73]

@shirhatti @JunTaoLuo This test has a 100% pass rate for the last 30 days. Considering there's a whole class of tests affected, does it makes sense to keep this single test quarantined?

[shirhatti]

Yeah, the other tests are a little more defensive better written. My initial analysis in the issue was incorrect.

[davidfowl]

statics are evil