search

microsoft / vstest

Visual Studio Test Platform is the runner and engine that powers test explorer and vstest.console.
MIT License
900 stars 323 forks source link

Data Collector Errors Cause TRX Result to be Failed #10391

Open hankweber opened 1 month ago

hankweber commented 1 month ago

We have tests where all of the tests pass, but there are data collector errors which then cause the overall result of the trx file to be marked as failed. Is there a way to bypass this logic and treat data collector errors as warnings?

nohwnd commented 1 month ago

I don't think there is a generic option to treat all collector errors as warnings. Is there a specific collector that you are having problems with? Maybe they have an option for this.

felixb-croesus commented 2 weeks ago

I think I have the same thing here. I run a test suite twice (sequentially) firstly targeting net8.0, then net462. Locally everything works, trx files are created with no errors, but in my CI run Blame works fine on the first test run (net8.0) but crashes on net462 after every tests passed.

This is my dotnet setup:

        DotNetTest(s => s
                    .SetProjectFile(E2ETestsProjectFile)
                    .SetConfiguration(Configuration)
                    .EnableNoBuild()
                    .SetFramework("net8.0")
                    .SetLoggers("console;verbosity=detailed")
                    .SetProcessArgumentConfigurator(args => args.Add($"--blame-hang-timeout 5m --logger:trx;LogFileName={dateTimeNow}_net8_0_test_results.trx"))
                );
        DotNetTest(s => s
                    .SetProjectFile(E2ETestsProjectFile)
                    .SetConfiguration(Configuration)
                    .EnableNoBuild()
                    .SetFramework("net462")
                    .SetLoggers("console;verbosity=detailed")
                    .SetProcessArgumentConfigurator(args => args.Add($"--blame-hang-timeout 5m --logger:trx;LogFileName={dateTimeNow}_net462_test_results.trx"))
                );

This is my error:

22:31:41 [ERR] The active test run was aborted. Reason: Test host process crashed
22:31:41 [DBG] Data collector 'Blame' message: The specified inactivity time of 5 minutes has elapsed. Collecting hang dumps from testhost and its child processes.
  Error: Data collector 'Blame' message: Data collector caught an exception of type 'System.IO.FileNotFoundException': 'Collect dump was enabled but no dump file was generated.'. More details: Blame: Collecting hang dump failed with error...
22:31:41 [ERR] Data collector 'Blame' message: Data collector caught an exception of type 'System.IO.FileNotFoundException': 'Collect dump was enabled but no dump file was generated.'. More details: Blame: Collecting hang dump failed with error...
22:31:41 [DBG] Data collector 'Blame' message: All tests finished running, Sequence file will not be generated.

  Error: Test Run Aborted.
 22:31:41 [ERR] Test Run Aborted.
 22:31:41 [DBG] Total tests: Unknown
 22:31:41 [DBG]      Passed: 7
 22:31:41 [DBG]  Total time: 6.2070 Minutes
 22:31:41 [DBG] Results File: /home/runner/work/Project/Tests/E2E/TestResults/20241106_222415_net462_test_results.trx

So the trx is created, my 7 tests passed, but the test run is marked as failure. Am I missing something obvious?

NOTE: It was working fine when I only had one test run (only net8.0)

felixb-croesus commented 2 weeks ago

Activated the --diag option,

C:\Program Files\dotnet\sdk\8.0.403\Extensions\Microsoft.VisualStudio.TestPlatform.Extensions.Trx.TestLogger.dll
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.040, 6998447518136, vstest.console.dll, AssemblyResolver.AddSearchDirectories: Adding more searchDirectories C:\Program Files\dotnet\sdk\8.0.403\Extensions,C:\Program Files\dotnet\sdk\8.0.403
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.040, 6998447518491, vstest.console.dll, AssemblyResolver.AddSearchDirectories: Adding more searchDirectories C:\Program Files\dotnet\sdk\8.0.403\Extensions,C:\Program Files\dotnet\sdk\8.0.403
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.040, 6998447518711, vstest.console.dll, AssemblyResolver.AddSearchDirectories: Adding more searchDirectories C:\Program Files\dotnet\sdk\8.0.403\Extensions,C:\Program Files\dotnet\sdk\8.0.403
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.040, 6998447518922, vstest.console.dll, AssemblyResolver.AddSearchDirectories: Adding more searchDirectories C:\Program Files\dotnet\sdk\8.0.403\Extensions,C:\Program Files\dotnet\sdk\8.0.403
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.040, 6998447519132, vstest.console.dll, AssemblyResolver.AddSearchDirectories: Adding more searchDirectories C:\Program Files\dotnet\sdk\8.0.403\Extensions,C:\Program Files\dotnet\sdk\8.0.403
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.040, 6998447519395, vstest.console.dll, AssemblyResolver.AddSearchDirectories: Adding more searchDirectories C:\Program Files\dotnet\sdk\8.0.403\Extensions,C:\Program Files\dotnet\sdk\8.0.403
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.041, 6998447522213, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Diagnostics.NETCore.Client: Resolving assembly.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.041, 6998447522846, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Diagnostics.NETCore.Client: Searching in: 'C:\Program Files\dotnet\sdk\8.0.403\Extensions'.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.055, 6998447667485, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Diagnostics.NETCore.Client: Loading assembly 'C:\Program Files\dotnet\sdk\8.0.403\Extensions\Microsoft.Diagnostics.NETCore.Client.dll'.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.057, 6998447690020, vstest.console.dll, AssemblyResolver.OnResolve: Resolved assembly: Microsoft.Diagnostics.NETCore.Client, from path: C:\Program Files\dotnet\sdk\8.0.403\Extensions\Microsoft.Diagnostics.NETCore.Client.dll
TpTrace Verbose: 0 : 44200, 1, 2024/11/07, 12:49:22.062, 6998447731743, vstest.console.dll, MetadataReaderExtensionsHelper: Discovering extensions inside assembly 'Microsoft.Diagnostics.NETCore.Client, Version=0.2.10.30701, Culture=neutral, PublicKeyToken=31bf3856ad364e35' file path 'C:\Program Files\dotnet\sdk\8.0.403\Extensions\Microsoft.Diagnostics.NETCore.Client.dll'
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.073, 6998447850172, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Resolving assembly.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.074, 6998447851901, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Searching in: 'C:\Program Files\dotnet\sdk\8.0.403\Extensions'.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.074, 6998447854761, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Assembly path does not exist: 'C:\Program Files\dotnet\sdk\8.0.403\Extensions\Microsoft.Bcl.AsyncInterfaces.dll', returning.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.074, 6998447856841, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Assembly path does not exist: 'C:\Program Files\dotnet\sdk\8.0.403\Extensions\Microsoft.Bcl.AsyncInterfaces.exe', returning.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.074, 6998447857780, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Searching in: 'C:\Program Files\dotnet\sdk\8.0.403'.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.074, 6998447860085, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Assembly path does not exist: 'C:\Program Files\dotnet\sdk\8.0.403\Microsoft.Bcl.AsyncInterfaces.dll', returning.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.075, 6998447862134, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Assembly path does not exist: 'C:\Program Files\dotnet\sdk\8.0.403\Microsoft.Bcl.AsyncInterfaces.exe', returning.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.075, 6998447862873, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Failed to load assembly.
TpTrace Verbose: 0 : 44200, 1, 2024/11/07, 12:49:22.075, 6998447863694, vstest.console.dll, CurrentDomainAssemblyResolve: Resolving assembly 'Microsoft.Bcl.AsyncInterfaces'.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.075, 6998447865019, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Resolving assembly.
TpTrace Information: 0 : 44200, 1, 2024/11/07, 12:49:22.075, 6998447865797, vstest.console.dll, AssemblyResolver.OnResolve: Microsoft.Bcl.AsyncInterfaces: Resolved from cache.
TpTrace Verbose: 0 : 44200, 1, 2024/11/07, 12:49:22.075, 6998447866282, vstest.console.dll, CurrentDomainAssemblyResolve: Resolving assembly 'Microsoft.Bcl.AsyncInterfaces'.
TpTrace Verbose: 0 : 44200, 1, 2024/11/07, 12:49:22.075, 6998447867457, vstest.console.dll, CurrentDomainAssemblyResolve: Failed to resolve assembly 'Microsoft.Bcl.AsyncInterfaces'.
TpTrace Verbose: 0 : 44200, 1, 2024/11/07, 12:49:22.079, 6998447905197, vstest.console.dll, CurrentDomainAssemblyResolve: Failed to resolve assembly 'Microsoft.Bcl.AsyncInterfaces'.

And the interesting part (probably the error in my CI):

TpTrace Warning: 0 : 44200, 1, 2024/11/07, 12:49:22.098, 6998448100328, vstest.console.dll, TestPluginDiscoverer: Failed to get types from assembly 'Microsoft.Diagnostics.NETCore.Client, Version=0.2.10.30701, Culture=neutral, PublicKeyToken=31bf3856ad364e35'. Error: System.Reflection.ReflectionTypeLoadException: Unable to load one or more of the requested types.
Could not load file or assembly 'Microsoft.Bcl.AsyncInterfaces, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51'. The system cannot find the file specified.
   at System.Reflection.RuntimeModule.GetTypes(RuntimeModule module)
   at System.Reflection.RuntimeModule.GetTypes()
   at Microsoft.VisualStudio.TestPlatform.Common.ExtensionFramework.TestPluginDiscoverer.GetTestExtensionsFromAssembly[TPluginInfo,TExtension](Assembly assembly, Dictionary`2 pluginInfos, String filePath) in /_/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginDiscoverer.cs:line 158

System.IO.FileNotFoundException: Could not load file or assembly 'Microsoft.Bcl.AsyncInterfaces, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51'. Le fichier spécifié est introuvable.
File name: 'Microsoft.Bcl.AsyncInterfaces, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51'
 ---> System.IO.FileNotFoundException: Could not load file or assembly 'Microsoft.Bcl.AsyncInterfaces, Culture=neutral, PublicKeyToken=null'. The system cannot find the file specified..

Not sure what to do with that..

felixb-croesus commented 2 weeks ago

Hmm, I actually saw something funny. I just noticed that locally, my runtime is Microsoft.NET\Framework64\v4.0.30319 (works fine) and in my linux CI, the runtime is mono/4.5 (hangs). testhost versions also don't match between net8 and net462

On my net8 run, the testhost.dll is using version 17.11.1 with runtime Microsoft.NETCore.App/8.0.10,

TpTrace Verbose: 0 : 4854, 1, 2024/11/07, 19:16:43.845, 226973172875, testhost.dll, Version: 17.11.1 Current process architecture: X64
TpTrace Verbose: 0 : 4854, 1, 2024/11/07, 19:16:43.849, 226977148328, testhost.dll, Runtime location: /usr/share/dotnet/shared/Microsoft.NETCore.App/8.0.10

But on my net462 run, testhost.exe is using version 17.11.1-release-24455-02 with runtime mono/4.5

TpTrace Verbose: 0 : 5975, 1, 2024/11/07, 19:17:52.703, 2958312304, testhost.exe, Version: 17.11.1-release-24455-02 Current process architecture: X64
TpTrace Verbose: 0 : 5975, 1, 2024/11/07, 19:17:52.706, 2958344480, testhost.exe, Runtime location: /usr/lib/mono/4.5

I also noticed at the end of the runs

net8.0: Works perfectly with a closed connection.

"TestRunStatistics":{"ExecutedTests":7,"Stats":{"Passed":7}},"ActiveTests":[]},"RunAttachments":[],"ExecutorUris":["executor://xunit/VsTestRunner2/netcoreapp"]}}

TpTrace Verbose: 0 : 4854, 4, 2024/11/07, 19:17:50.685, 293813030807, testhost.dll, BaseRunTests.RunTests: Run is complete.
TpTrace Verbose: 0 : 4854, 5, 2024/11/07, 19:17:50.685, 293813419908, testhost.dll, TcpClientExtensions.MessageLoopAsync: NotifyDataAvailable remoteEndPoint: [::ffff:127.0.0.1]:45973 localEndPoint: [::ffff:127.0.0.1]:40596

TpTrace Information: 0 : 4854, 5, 2024/11/07, 19:17:50.685, 293813496261, testhost.dll, TestRequestHandler.OnMessageReceived: received message: (TestSession.Terminate) -> {"MessageType":"TestSession.Terminate","Payload":null}

TpTrace Information: 0 : 4854, 5, 2024/11/07, 19:17:50.685, 293813529604, testhost.dll, Session End message received from server. Closing the connection.

net462: Hangs at the end of the test run

"TestRunStatistics":{"ExecutedTests":7,"Stats":{"Passed":7}},"ActiveTests":[]}}
TpTrace Verbose: 0 : 5975, 21, 2024/11/07, 19:19:32.395, 3955227857, testhost.exe, TestRunCache: OnNewTestResult: Notified the onCacheHit callback.

TpTrace Verbose: 0 : 5975, 6, 2024/11/07, 19:19:33.242, 3963701401, testhost.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:37387 localEndPoint: 127.0.0.1:59032 after 1001 ms
TpTrace Verbose: 0 : 5975, 6, 2024/11/07, 19:19:34.243, 3973712900, testhost.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:37387 localEndPoint: 127.0.0.1:59032 after 1001 ms
TpTrace Verbose: 0 : 5975, 6, 2024/11/07, 19:19:35.244, 3983720642, testhost.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:37387 localEndPoint: 127.0.0.1:59032 after 1000 ms

And it just loops on the polling untill I reach my timeout. So the hang is actually caused by the test host and not my tests. Any idea what's happening? Any known issues between mono and your testhost?

felixb-croesus commented 2 weeks ago

@nohwnd Would you like that I create a new issue? Or do you need more info? Thank you! :)