[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
959287	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmBuildAppTest.WorkItemExecution
958944	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmBuildAppTest.WorkItemExecution
958091	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmBuildAppTest.WorkItemExecution	#111700
958555	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmBuildAppTest.WorkItemExecution
958086	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution	#112005
956643	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution
955917	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmBuildAppTest.WorkItemExecution
954209	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution	#112628
954206	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution	#112627
953809	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution	#112514
953428	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmBuildAppTest.WorkItemExecution	#112514
952563	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution	#112522
952228	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuTests.WorkItemExecution	#112552
952232	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution	#112394
951298	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmBuildAppTest.WorkItemExecution	#112522
951146	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution
951012	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution
950905	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution	#112515
950902	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution	#112514
950260	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.NativeLibraryTests.WorkItemExecution	#112468
950161	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.NativeLibraryTests.WorkItemExecution
949810	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmBuildAppTest.WorkItemExecution	#112373
949816	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution	#112296
949867	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution
949051	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution
948890	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution
948453	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution	#112428
948414	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution
947915	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution	#112012
947948	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution
947748	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.InvariantTimezoneTests.WorkItemExecution	#112394
947524	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution	#112382
947381	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.NativeLibraryTests.WorkItemExecution	#112340
947434	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution
947293	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.NativeLibraryTests.WorkItemExecution	#112261
947290	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.IcuShardingTests.WorkItemExecution	#112225
946906	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuTests.WorkItemExecution
946600	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.IcuTests.WorkItemExecution	#111655
945634	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution	#111655
946280	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution	#112340
945126	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution	#112296
944409	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution
942018	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution	#111885
938208	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.WasmSIMDTests.WorkItemExecution	#111655
935293	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution	#112012
935005	dotnet/runtime	Workloads-NoWebcil-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution	#112005
926240	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution	#111737
927457	dotnet/runtime	Workloads-ST-Wasm.Build.Tests.BuildPublishTests.WorkItemExecution

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
4	11	48

[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