[browser][wbt] fails with InvalidOperationException: There is no currently active test

[ilonatommy]

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=751591
Build error leg or test failing: Workloads-NoWebcil-NoFingerprint-ST-Wasm.Build.Tests.WorkItemExecution
Pull request: #105302

Error Message

Fill the error message using step by step known issues guidance.

{
  "ErrorMessage": "Unhandled exception. System.InvalidOperationException: There is no currently active test.",
  "ErrorPattern": "",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: 🔎 https://dev.azure.com/dnceng-public/public/_build/results?buildId=751591
Error message validated: [Unhandled exception. System.InvalidOperationException: There is no currently active test.]
Result validation: ✅ Known issue matched with the provided build.
Validation performed at: 7/23/2024 1:57:11 PM UTC

Report

Build	Definition	Test	Pull Request
900929	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution	#110878
900905	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
0	0	2

[dotnet-policy-service]

Tagging subscribers to this area: @dotnet/area-infrastructure-libraries
See info in area-owners.md if you want to be subscribed.

[dotnet-policy-service]

Tagging subscribers to this area: @directhex, @matouskozak
See info in area-owners.md if you want to be subscribed.

[maraf]

I'm not able to reproduce it locally. It doesn't seem related to fingerprinting.
The message comes from xunit orchestration. It looks like a race condition.

[maraf]

@mkhamoyan Can you please look into this one? It's quite low priority (if don't start happening more often, but it doesn't seem so far). The exception comes from ToolCommand https://github.com/dotnet/runtime/blob/main/src/mono/wasm/Wasm.Build.Tests/Common/ToolCommand.cs#L110
My theory is that the process output arrives in .NET after the waiting for process to finish (as thus the test finished). Something like unsubscribing the handlers after the wait might be enough.

[ilonatommy]

Note for the future: unsubscribing from the handlers did not fully fix the issue, the last 2 hits are on PRs created after the fix was merged.

[ilonatommy]

Following the stack:

runtime/src/mono/wasm/Wasm.Build.Tests/BuildTestBase.cs

Line 548 in 84b7c2f

_testOutput.WriteLine($"{label} {message}");

https://github.com/xunit/xunit/blob/6bfa188331f6d4ed6e877ab6da5e7b2725ccd721/src/xunit.v3.core/Framework/TestOutputHelper.cs#L45

We might be trying to WriteLine in a try-catch, after xunit threw an exception. I'm gonna wrap
protected readonly ITestOutputHelper _testOutput;
in a custom class, that would call ITestOutputHelper's methods in its own try-catch and log to console in case something goes wrong.

[ilonatommy]

Sample log:

    Wasm.Build.Tests.SatelliteAssembliesTests.ResourcesFromMainAssembly(buildArgs: BuildArgs { ProjectName = placeholder, Config = Release, AOT = False, ProjectFileContents = placeholder, ExtraBuildArgs =  }, nativeRelink: True, argCulture: "es-ES", host: V8, id: "iomynnb2_4h0") [STARTING]

** -------- publish -------- **

Binlog path: /root/helix/work/workitem/uploads/xharness-output/logs/iomynnb2_4h0/iomynnb2_4h0-publish.binlog
[] Executing (Captured Output) - /root/helix/work/workitem/e/dotnet-latest/dotnet publish -bl:/root/helix/work/workitem/uploads/xharness-output/logs/iomynnb2_4h0/iomynnb2_4h0-publish.binlog -p:Configuration=Release -nr:false   -  in pwd /root/helix/work/workitem/e/wbt artifacts/iomynnb2_4h0
	[DOTNET_ROOT] = /root/helix/work/workitem/e/dotnet-latest
	[DOTNET_INSTALL_DIR] = /root/helix/work/workitem/e/dotnet-latest
	[DOTNET_MULTILEVEL_LOOKUP] = 0
	[DOTNET_SKIP_FIRST_TIME_EXPERIENCE] = 1
	[PATH] = /root/helix/work/workitem/e/dotnet-latest:/__w/1/s/artifacts/bin/geckodriver/geckodriver:/root/helix/work/correlation/dotnet-latest:/root/helix/work/correlation/xharness-cli:/root/helix/work/correlation/dotnet-cli:/root/helix/work/correlation/chrome-linux:/root/helix/work/correlation/chromedriver_linux64:/home/helixbot/.jsvu/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
	[EM_WORKAROUND_PYTHON_BUG_34780] = 1
	[WasmEnableWebCil] = false
	[NUGET_PACKAGES] = /root/helix/work/workitem/e/wbt artifacts/nuget/iomynnb2_4h0
[]   Determining projects to restore...
Unhandled exception. System.InvalidOperationException: There is no currently active test.
   at Xunit.Sdk.TestOutputHelper.QueueTestOutput(String output) in /_/src/xunit.execution/Sdk/Frameworks/TestOutputHelper.cs:line 61
   at Wasm.Build.Tests.BuildTestBase.<>c__DisplayClass47_0.<RunProcessAsync>g__LogData|0(String label, String message) in /_/src/mono/wasm/Wasm.Build.Tests/BuildTestBase.cs:line 544
   at System.Diagnostics.AsyncStreamReader.FlushMessageQueue(Boolean rethrowInNewThread)
--- End of stack trace from previous location ---
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
./RunTests.sh: line 102:    80 Aborted                 (core dumped) dotnet exec xunit.console.dll Wasm.Build.Tests.dll -xml $XHARNESS_OUT/testResults.xml $HELIX_XUNIT_ARGS -nocolor -verbose -notrait category=IgnoreForCI -notrait category=failing $XUnitTraitArg $RSP_FILE

All the available failure logs are from Linux.

[ilonatommy]

The last 2 hits are on PRs that had the #108319 change. It's still unfixed