[v12] Headless Test Case Cleanup Failure with 'Cannot get KeyValueStorage on the idle test context'

[ppaszkiewiczcom]

Describe the bug

After updating to Avalonia 12 and xUnit 3, I'm unable to run headless tests.

Tests that used to work fine in Avalonia 11 with xUnit2 now at some point "randomly" fail with:

[Test Case Cleanup Failure (MyTestClass.TestNameHere)] System.InvalidOperationException

• when this happens with dotnet run test run immediately ends.
• when this happens with dotnet test all following cases collapse by throwing same exception.
• when this happens in visual studio test explorer, errors are silently swallowed and tests "succeed" despite only running part of test suite, for example 20 / 150 cases

Exception stack:

System.InvalidOperationException
  HResult=0x80131509
  Message=Cannot get KeyValueStorage on the idle test context
  Source=xunit.v3.core
  StackTrace:
   at Xunit.TestContext.get_KeyValueStorage() in /_/src/xunit.v3.core/TestContext.cs:line 111
   at Xunit.TestContext.SetForTest(ITest test, TestEngineStatus testStatus, CancellationToken cancellationToken, TestResultState testState, ITestOutputHelper testOutputHelper, Object testClassInstance) in /_/src/xunit.v3.core/TestContext.cs:line 360
   at Xunit.v3.TestRunnerBase`2.SetTestContext(TContext ctxt, TestEngineStatus testStatus, TestResultState testState, Object testClassInstance) in /_/src/xunit.v3.core/Runners/TestRunnerBase.cs:line 521
   at Xunit.v3.TestRunnerBase`2.SetTestContext(TContext ctxt, TestEngineStatus testStatus, Boolean dispose, TestResultState testState, Object testClassInstance) in /_/src/xunit.v3.core/Runners/TestRunnerBase.cs:line 538
   at Xunit.v3.TestRunnerBase`2.<Run>d__13.MoveNext() in /_/src/xunit.v3.core/Runners/TestRunnerBase.cs:line 393
   at System.Threading.Tasks.ValueTask`1.get_Result() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/ValueTask.cs:line 816
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult() in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/ValueTaskAwaiter.cs:line 126
   at Avalonia.Headless.XUnit.AvaloniaTestRunner.<>c__DisplayClass4_0.<<Run>b__0>d.MoveNext() in /_/src/Headless/Avalonia.Headless.XUnit/AvaloniaTestRunner.cs:line 44
   at Avalonia.Headless.HeadlessUnitTestSession.<>c__DisplayClass12_0`1.<DispatchCore>b__0() in /_/src/Headless/Avalonia.Headless/HeadlessUnitTestSession.cs:line 125
--- End of stack trace from previous location ---
   at Avalonia.Headless.XUnit.AvaloniaTestRunner.<Run>d__4.MoveNext() in /_/src/Headless/Avalonia.Headless.XUnit/AvaloniaTestRunner.cs:line 40
   at Avalonia.Headless.XUnit.AvaloniaTestRunner.<Run>d__4.MoveNext() in /_/src/Headless/Avalonia.Headless.XUnit/AvaloniaTestRunner.cs:line 40

  This exception was originally thrown at this call stack:
    Xunit.TestContext.KeyValueStorage.get() in TestContext.cs
    Xunit.TestContext.SetForTest(Xunit.Sdk.ITest, Xunit.TestEngineStatus, System.Threading.CancellationToken, Xunit.TestResultState, Xunit.ITestOutputHelper, object) in TestContext.cs
    Xunit.v3.TestRunnerBase<TContext, TTest>.SetTestContext(TContext, Xunit.TestEngineStatus, Xunit.TestResultState, object) in TestRunnerBase.cs
    Xunit.v3.TestRunnerBase<TContext, TTest>.SetTestContext(TContext, Xunit.TestEngineStatus, bool, Xunit.TestResultState, object) in TestRunnerBase.cs
    Xunit.v3.TestRunnerBase<TContext, TTest>.Run(TContext) in TestRunnerBase.cs
    System.Threading.Tasks.ValueTask<TResult>.Result.get() in ValueTask.cs
    System.Runtime.CompilerServices.ValueTaskAwaiter<TResult>.GetResult() in ValueTaskAwaiter.cs
    Avalonia.Headless.XUnit.AvaloniaTestRunner.Run.AnonymousMethod__0() in AvaloniaTestRunner.cs
    Avalonia.Headless.HeadlessUnitTestSession.DispatchCore.AnonymousMethod__0() in HeadlessUnitTestSession.cs
    Avalonia.Headless.XUnit.AvaloniaTestRunner.Run(Xunit.v3.IXunitTest, Xunit.v3.IMessageBus, object[], Xunit.Sdk.ExplicitOption, Xunit.v3.ExceptionAggregator, System.Threading.CancellationTokenSource, System.Collections.Generic.IReadOnlyCollection<Xunit.v3.IBeforeAfterTestAttribute>, Avalonia.Headless.HeadlessUnitTestSession) in AvaloniaTestRunner.cs
    ...
    [Call Stack Truncated]

To Reproduce

I was not able to isolate the issue or produce a sample as the error stack doesn't seem to come from our code.

However test content does seem to affect it: unless I open our "MainWindow" and fill it with data/engage viewmodels into some work tests won't fail.
Additionally adding extra Task.Delay(1000) to DisposeAsync seems to "stabilize" the error a bit (on average run more cases before failing but they still do).

The fact that entire xunit runner layer (where call stack comes from) is full of multi-level inheritance and lambdas wrapping other lambdas has made it very unfriendly to investigate on my own.

Expected behavior

• Ideally: Entire test suite should execute; cleanup error of one test should not collapse all of the subsequent cases
• Preferably: exception should lead to user code (if it's the cause)

Avalonia version

12.0.2

OS

Windows

Additional context

No response

[timunie]

Without a sample it's hard to digg into.

Maybe best bet is to reference Avalonia from source directly so you can add some logging or something.

[ppaszkiewiczcom]

I did a bit more investigation and the issue seems to related to use of AsyncLocal<TestContext?> local in Xunit.TestContext.

AvaloniaTestRunner runs fine for a moment but at some point reference in Xunit.TestContext.local becomes null which causes SetTextContext to fail when AvaloniaTestRunner calls TestContext.SetForTest that requires earlier TestContext to already be present.

So the error being a bit cryptic is oversight on XUnit part, but the issue of Xunit.TestContext.local being purged/lost in between test runs still eludes me.

Could this be that HeadlessUnitTestSession.Dispatch changes async context between tests under some circumstance? (note: I haven't used AsyncLocal before, so I'm only guessing)

[mikegoatly]

@ppaszkiewiczcom I think you're right, but don't know enough about the intent here in HeadlessUnitTestSession:

/// <inheritdoc cref="DispatchCore{TResult}"/>
public Task<TResult> Dispatch<TResult>(Func<Task<TResult>> action, CancellationToken cancellationToken)
{
    return DispatchCore(action, false, cancellationToken); // <-- Line 69, Passing captureExecutionContext as false
}

It might be that passing captureExecutionContext as true will fix this - that's what's used in the NUnit headless AvaloniaTestMethodCommand:

public override TestResult Execute(TestExecutionContext context)
{
    return _session.DispatchCore(() => ExecuteTestMethod(context), true, context.CancellationToken).GetAwaiter().GetResult();
}

I can repo this in the CI build for my application about 50% of the time, but never locally, making it hard for me to test the fix. If you can run your code against the Avalonia source with that line changed, does it help?

[timunie]

@mikegoatly you could open a PR that should create a preview package for you automatically. This can be tested from CI run, just in case.

[ppaszkiewiczcom]

@mikegoatly Hey,

I ran my tests with build from PR and they seem to work correctly.

I've made [AvaloniaTheory] that only launched main window and loaded basic data and was executed 200 times.

With release build it only runs about 5-50 times.

With PR build it goes through all 200 times. Even tried 800 with no issues.