[browser][wbt] fails with `InvalidOperationException: There is no currently active test`
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: https://github.com/dotnet/runtime/pull/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: :mag_right: 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: :white_check_mark: Known issue matched with the provided build.
Validation performed at: 7/23/2024 1:57:11 PM UTC
Report
Summary
| 24-Hour Hit Count | 7-Day Hit Count | 1-Month Count |
|---|---|---|
| 3 | 9 | 39 |
Tagging subscribers to this area: @dotnet/area-infrastructure-libraries See info in area-owners.md if you want to be subscribed.
Tagging subscribers to this area: @directhex, @matouskozak See info in area-owners.md if you want to be subscribed.
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.
@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.
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.
Following the stack: https://github.com/dotnet/runtime/blob/84b7c2f15ceec32e66b46231614dfcb3e334c6fd/src/mono/wasm/Wasm.Build.Tests/BuildTestBase.cs#L548
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.
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.
The last 2 hits are on PRs that had the https://github.com/dotnet/runtime/pull/108319 change. It's still unfixed
@ilonatommy this looks like it is showing up a lot in release/9.0
@ilonatommy this looks like it is showing up a lot in release/9.0
If it's much more than on net10 then let's backport https://github.com/dotnet/runtime/pull/108319, https://github.com/dotnet/runtime/pull/108387, https://github.com/dotnet/runtime/pull/105561
Edit: the unsubscribing is already backported, so only the exception logging related changes.
There are no hits on net10 because we stopped running tests with self-created process in the refactoring PR: https://github.com/dotnet/runtime/pull/109069 and we are not keeping handlers for logging manually but we rely on Playwrigt to run the tests. The previously backported PRs is not a full fix.
The only hits after the fix are net8 where we did not backport and they are very rare.