microsoft/vstest

dotnet test does not discovers tests (xunit + mac)

Closed this issue ยท 16 comments

From @RassulYunussov at https://github.com/dotnet/cli/issues/5949

Interesting thing happening when I add xunit tests to my project.
When I start test using command: dotnet test within Visual Studio Code Terminal - everything goes ok. All tests run.
But when I run dotnet test from a terminal (without Visual Studio Code) I get error message that says that there is no test available.

Steps to reproduce

dotnet test

Expected behavior

(within Visual Studio Code)
Build started, please wait...
Build completed.

Test run for /.../bin/Debug/netcoreapp1.1/SomeProject.Tests.dll(.NETCoreApp,Version=v1.1)
Microsoft (R) Test Execution Command Line Tool Version 15.0.0.0
Copyright (c) Microsoft Corporation. All rights reserved.
Starting test execution, please wait...
[xUnit.net 00:00:01.2838115] Discovering: SomeProject.Tests
[xUnit.net 00:00:01.4470527] Discovered: SomeProject.Tests
[xUnit.net 00:00:01.5129059] Starting: SomeProject.Tests
[xUnit.net 00:00:01.7132244] Finished: SomeProject.Tests

Total tests: 1. Passed: 1. Failed: 0. Skipped: 0.
Test Run Successful.
Test execution time: 2.7660 Seconds

Actual behavior

(from terminal)
Build started, please wait...
Build completed.

Test run for /.../bin/Debug/netcoreapp1.1/SomeProject.Tests.dll(.NETCoreApp,Version=v1.1)
Microsoft (R) Test Execution Command Line Tool Version 15.0.0.0
Copyright (c) Microsoft Corporation. All rights reserved.
Starting test execution, please wait...
No test is available in /.../bin/Debug/netcoreapp1.1/SomeProject.Tests.dll. Make sure that installed test discoverers & executors, platform & framework version settings are appropriate and try again.

Environment data

dotnet --info output:
.NET Command Line Tools (1.0.1)

Product Information:
Version: 1.0.1
Commit SHA-1 hash: 005db40cd1

Runtime Environment:
OS Name: Mac OS X
OS Version: 10.12
OS Platform: Darwin
RID: osx.10.12-x64
Base Path: /usr/local/share/dotnet/sdk/1.0.1

@RassulYunussov can you please share csproj file and log files(which you can get running dotnet test --diag:log.txt) log.txt and log.host.<timestamp>.txt.

Yes, I can do it.
I have replaced sensitive information by "...".

Here they are:
csproj file:
<Project Sdk="Microsoft.NET.Sdk"> <PropertyGroup> <TargetFramework>netcoreapp1.1</TargetFramework> </PropertyGroup> <ItemGroup> <PackageReference Include="Microsoft.NET.Test.Sdk" Version="15.0.0" /> <PackageReference Include="xunit" Version="2.2.0" /> <PackageReference Include="xunit.runner.visualstudio" Version="2.2.0" /> </ItemGroup> <ItemGroup> <ProjectReference Include="..\SomeProject\SomeProject.csproj" /> </ItemGroup> </Project>

Log.host....txt:

TpTrace Information: 0 : 677, 1, 2017/03/09, 07:12:51.622, 209059021219, testhost.dll, DefaultEngineInvoker: Monitoring parent process with id: '676'
TpTrace Information: 0 : 677, 1, 2017/03/09, 07:12:51.642, 209076753067, testhost.dll, DefaultEngineInvoker: Initialize communication on port number: '49359'
TpTrace Information: 0 : 677, 1, 2017/03/09, 07:12:51.652, 209086759627, testhost.dll, Trying to connect to server on port : 49359
TpTrace Information: 0 : 677, 6, 2017/03/09, 07:12:51.675, 209109220301, testhost.dll, Connected to the server successfully
TpTrace Information: 0 : 677, 1, 2017/03/09, 07:12:51.993, 209427682981, testhost.dll, DefaultEngineInvoker: Start Request Processing.
TpTrace Information: 0 : 677, 6, 2017/03/09, 07:12:52.068, 209503088359, testhost.dll, Discovery Session Initialize.
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.096, 209530999734, testhost.dll, TestPluginCache: Updating loadOnlyWellKnownExtensions from False to False.
TpTrace Information: 0 : 677, 6, 2017/03/09, 07:12:52.103, 209537868931, testhost.dll, Execution started.
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.106, 209540461349, testhost.dll, TestPluginCache: Using directories for assembly resolution '/.../SomeProject.Tests/bin/Debug/netcoreapp1.1'.
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.106, 209540616812, testhost.dll, TestPluginCache: Updated the available extensions to '/.../SomeProject.Tests/bin/Debug/netcoreapp1.1/xunit.runner.visualstudio.dotnetcore.testadapter.dll'.
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.107, 209541527381, testhost.dll, TestExecutorService: Loading the extensions
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.116, 209550491842, testhost.dll, TestPluginCache: Discovering the extensions using extension path.
TpTrace Error: 0 : 677, 3, 2017/03/09, 07:12:52.117, 209551252954, testhost.dll, Default extensions folder does not exist
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.130, 209564896730, testhost.dll, TestPluginCache: Discovered the extensions using extension path '/.../SomeProject.Tests/bin/Debug/netcoreapp1.1/xunit.runner.visualstudio.dotnetcore.testadapter.dll'.
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.132, 209566373566, testhost.dll, TestPluginCache: Discoverers are 'Xunit.Runner.VisualStudio.TestAdapter.VsTestRunner, xunit.runner.visualstudio.dotnetcore.testadapter, Version=2.2.0.1274, Culture=neutral, PublicKeyToken=8d05b1bb7a6fdb6c'.
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.132, 209566457792, testhost.dll, TestPluginCache: Executors are 'executor://xunit/VsTestRunner2'.
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.132, 209566537457, testhost.dll, TestPluginCache: Setting providers are ''.
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.132, 209566570644, testhost.dll, TestPluginCache: Loggers are ''.
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:52.139, 209573577193, testhost.dll, TestPluginManager.CreateTestExtension: Attempting to load test extension: Xunit.Runner.VisualStudio.TestAdapter.VsTestRunner
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.139, 209573741213, testhost.dll, TestDiscoveryManager: LoadExtensions: Created discoverer Xunit.Runner.VisualStudio.TestAdapter.VsTestRunner
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.139, 209573802081, testhost.dll, TestExecutorService: Loaded the discoverers
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:52.147, 209582098314, testhost.dll, TestPluginManager.CreateTestExtension: Attempting to load test extension: Xunit.Runner.VisualStudio.TestAdapter.VsTestRunner
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.148, 209582237681, testhost.dll, TestExecutorExtensionManager: Loading executor Xunit.Runner.VisualStudio.TestAdapter.VsTestRunner
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.148, 209582275562, testhost.dll, TestExecutorService: Loaded the executors
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.153, 209587616174, testhost.dll, TestExecutorService: Loaded the settings providers
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:52.153, 209587726649, testhost.dll, TestExecutorService: Loaded the extensions
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:52.246, 209680600483, testhost.dll, AssemblyResolver: Microsoft.VisualStudio.TestPlatform.Common.resources: Resolving assembly.
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:52.250, 209684504945, testhost.dll, AssemblyResolver: Microsoft.VisualStudio.TestPlatform.Common.resources: Resolving assembly.
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:52.269, 209703972356, testhost.dll, TestDiscoveryManager: Discovering tests from sources /.../SomeProject.Tests/bin/Debug/netcoreapp1.1/SomeProject.Tests.dll
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:52.278, 209713011991, testhost.dll, BaseRunTests.RunTestInternalWithExecutors: Running tests for executor://xunit/VsTestRunner2
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:53.064, 210498820333, testhost.dll, TestExecutionManager.RunTestInternalWithExecutors: Completed running tests for executor://xunit/VsTestRunner2
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:53.067, 210501448002, testhost.dll, AssemblyResolver: Microsoft.TestPlatform.CrossPlatEngine.resources: Resolving assembly.
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:53.067, 210501815723, testhost.dll, AssemblyResolver: Microsoft.TestPlatform.CrossPlatEngine.resources: Resolving assembly.
TpTrace Warning: 0 : 677, 3, 2017/03/09, 07:12:53.068, 210502358630, testhost.dll, No test is available in /.../SomeProject.Tests/bin/Debug/netcoreapp1.1/SomeProject.Tests.dll. Make sure that installed test discoverers & executors, platform & framework version settings are appropriate and try again.
TpTrace Information: 0 : 677, 3, 2017/03/09, 07:12:53.072, 210506415109, testhost.dll, Sending test run complete
TpTrace Verbose: 0 : 677, 3, 2017/03/09, 07:12:53.122, 210556190417, testhost.dll, BaseRunTests.RunTests: Run is complete.
TpTrace Information: 0 : 677, 6, 2017/03/09, 07:12:53.156, 210590520149, testhost.dll, Session End message received from server. Closing the connection.
TpTrace Information: 0 : 677, 6, 2017/03/09, 07:12:53.173, 210607938564, testhost.dll, Closing the connection !

Log.txt:

TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.187, 208624860020, vstest.console.dll, TestPluginCache: Discovering the extensions using extension path.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:51.213, 208647622798, vstest.console.dll, AssemblyResolver: Microsoft.VisualStudio.TestPlatform.Extensions.TrxLogger: Resolving assembly.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:51.214, 208648281082, vstest.console.dll, AssemblyResolver: Microsoft.VisualStudio.TestPlatform.Extensions.TrxLogger: Resolved assembly.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.215, 208650065459, vstest.console.dll, TestPluginCache: Discovered the extensions using extension path ''.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.215, 208650196511, vstest.console.dll, TestPluginCache: Discoverers are ''.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.216, 208650260409, vstest.console.dll, TestPluginCache: Executors are ''.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.216, 208650317676, vstest.console.dll, TestPluginCache: Setting providers are ''.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.216, 208650382790, vstest.console.dll, TestPluginCache: Loggers are 'logger://Microsoft/TestPlatform/TrxLogger/v2'.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:51.221, 208656201432, vstest.console.dll, RunTestsArgumentProcessor:Execute: Test run is starting.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.241, 208675310422, vstest.console.dll, Using effective platform:X86 effective framework:.NETCoreApp,Version=v1.1
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.247, 208681427978, vstest.console.dll, RunTestsArgumentProcessor:Execute: Queuing Test run.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:51.247, 208681609192, vstest.console.dll, TestRequestManager.RunTests: run tests started.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.250, 208685243811, vstest.console.dll, TestEngine: Initializing Parallel Execution as MaxCpuCount is set to: 1
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.261, 208695416897, vstest.console.dll, TestRunRequest.ExecuteAsync: Creating test run request.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.261, 208696104348, vstest.console.dll, TestRunRequest.ExecuteAsync: Starting.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:51.262, 208696292348, vstest.console.dll, TestRunRequest.ExecuteAsync: Starting run with settings:TestRunCriteria:
KeepAlive=False,FrequencyOfRunStatsChangeEvent=10,RunStatsChangeEventTimeout=00:00:01.5000000,TestCaseFilter=,TestExecutorLauncher=
Settingsxml=

/.../SomeProject.Tests/TestResults
X86
.NETCoreApp,Version=v1.1

TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.262, 208696333973, vstest.console.dll, TestRunRequest.ExecuteAsync: Wait for the first run request is over.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:51.263, 208697486015, vstest.console.dll, TestRunRequest.ExecuteAsync: Started.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:51.263, 208697603717, vstest.console.dll, TestRunRequest.WaitForCompletion: Waiting with timeout -1.
TpTrace Information: 0 : 676, 5, 2017/03/09, 07:12:51.263, 208697696677, vstest.console.dll, ProxyParallelExecutionManager: Triggering test run for next source: /.../SomeProject.Tests/bin/Debug/netcoreapp1.1/SomeProject.Tests.dll
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.263, 208697933212, vstest.console.dll, ProxyExecutionManager: Test host is non shared. Lazy initialize.
TpTrace Information: 0 : 676, 5, 2017/03/09, 07:12:51.283, 208717719872, vstest.console.dll, Listening on port : 49359
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.300, 208735254447, vstest.console.dll, DotnetTestHostmanager: Full path of dotnet.exe is /usr/local/share/dotnet/dotnet
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.301, 208735386717, vstest.console.dll, DotnetTestHostmanager: Adding --runtimeconfig "/.../SomeProject.Tests/bin/Debug/netcoreapp1.1/SomeProject.Tests.runtimeconfig.json" in args
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.301, 208735469136, vstest.console.dll, DotnetTestHostmanager: Adding --depsfile "/.../SomeProject.Tests/bin/Debug/netcoreapp1.1/SomeProject.Tests.deps.json" in args
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.303, 208737761985, vstest.console.dll, DotnetTestHostmanager: Reading file /.../SomeProject.Tests/bin/Debug/netcoreapp1.1/SomeProject.Tests.deps.json to get path of testhost.dll
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.344, 208778846003, vstest.console.dll, DotnetTestHostmanager: Relative path of testhost.dll with respect to package folder is microsoft.testplatform.testhost/15.0.0/lib/netstandard1.5/testhost.dll
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.348, 208782333797, vstest.console.dll, DotnetTestHostmanager: Looking for path microsoft.testplatform.testhost/15.0.0/lib/netstandard1.5/testhost.dll in folder /Users/.../.nuget/packages
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.348, 208782491353, vstest.console.dll, DotnetTestHostmanager: Full path of testhost.dll is /Users/.../.nuget/packages/microsoft.testplatform.testhost/15.0.0/lib/netstandard1.5/testhost.dll
TpTrace Verbose: 0 : 676, 5, 2017/03/09, 07:12:51.348, 208782778873, vstest.console.dll, ProcessHelper: Starting process '/usr/local/share/dotnet/dotnet' with command line 'exec --runtimeconfig "/.../SomeProject.Tests/bin/Debug/netcoreapp1.1/SomeProject.Tests.runtimeconfig.json" --depsfile "/.../SomeProject.Tests/bin/Debug/netcoreapp1.1/SomeProject.Tests.deps.json" "/Users/.../.nuget/packages/microsoft.testplatform.testhost/15.0.0/lib/netstandard1.5/testhost.dll" --port 49359 --parentprocessid 676 --diag log.host.17-03-09_07-12-51_29629_5.txt'
TpTrace Information: 0 : 676, 4, 2017/03/09, 07:12:51.669, 209104135343, vstest.console.dll, Accepted Client request and set the flag
TpTrace Verbose: 0 : 676, 4, 2017/03/09, 07:12:51.999, 209433491476, vstest.console.dll, TestRunRequest:SendTestRunMessage: Starting.
TpTrace Information: 0 : 676, 4, 2017/03/09, 07:12:51.999, 209434158526, vstest.console.dll, TestRunRequest:SendTestRunMessage: Completed.
TpTrace Verbose: 0 : 676, 4, 2017/03/09, 07:12:53.068, 210502882875, vstest.console.dll, TestRunRequest:SendTestRunMessage: Starting.
TpTrace Information: 0 : 676, 4, 2017/03/09, 07:12:53.068, 210503019109, vstest.console.dll, TestRunRequest:SendTestRunMessage: Completed.
TpTrace Verbose: 0 : 676, 4, 2017/03/09, 07:12:53.155, 210589917728, vstest.console.dll, TestRunRequest:SendTestRunStatsChange: Starting.
TpTrace Information: 0 : 676, 4, 2017/03/09, 07:12:53.155, 210590113118, vstest.console.dll, TestRunRequest:SendTestRunStatsChange: Completed.
TpTrace Verbose: 0 : 676, 4, 2017/03/09, 07:12:53.162, 210596343722, vstest.console.dll, TestRunRequest:TestRunComplete: Starting. IsAborted:False IsCanceled:False.
TpTrace Information: 0 : 676, 4, 2017/03/09, 07:12:53.163, 210597972275, vstest.console.dll, TestRunRequest:TestRunComplete: Completed.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:53.163, 210598128927, vstest.console.dll, TestRunRequest.Dispose: Starting.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:53.164, 210598210377, vstest.console.dll, TestRunRequest.Dispose: Completed.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:53.164, 210598278833, vstest.console.dll, TestRequestManager.RunTests: run tests completed, sucessful: True.
TpTrace Information: 0 : 676, 1, 2017/03/09, 07:12:53.164, 210598322909, vstest.console.dll, RunTestsArgumentProcessor:Execute: Test run is completed.
TpTrace Verbose: 0 : 676, 1, 2017/03/09, 07:12:53.164, 210598369971, vstest.console.dll, Executor.Execute: Exiting with exit code of 0

I've just created a new project with tests and succeeded to run tests from terminal. But still can't do it for my old one. May be because of additional packages I use in my old project, like OpenIddict?

Similar issue: #516, adding particular package(Swashbuckle.AspNetCore-1.0.0-rc1) reference test not getting discovered. can you please provide all package reference in SomeProject.csproj.

< PackageReference Include="Microsoft.AspNetCore" Version="1.0.3" /> < PackageReference Include="Microsoft.AspNetCore.Mvc" Version="1.0.2" /> < PackageReference Include="Microsoft.Extensions.Logging.Debug" Version="1.0.1" /> < PackageReference Include="Microsoft.AspNetCore.Mvc.Formatters.Xml" Version="1.1.1"/> < PackageReference Include="Microsoft.AspNetCore.JsonPatch" Version="1.1.0"/> < PackageReference Include="Microsoft.EntityFrameworkCore.Sqlite" Version="1.1.0"/> < PackageReference Include="Microsoft.EntityFrameworkCore.Design" Version="1.1.0"/> < PackageReference Include="Swashbuckle" Version="6.0.0-beta902"/> < PackageReference Include="Microsoft.AspNetCore.Identity" Version="1.1.0"/> < PackageReference Include="Microsoft.AspNetCore.Identity.EntityFrameworkCore" Version="1.1.0"/> < PackageReference Include="AspNet.Security.OAuth.Validation" Version="1.0.0-*"/> < PackageReference Include="OpenIddict" Version="1.0.0-*"/> < PackageReference Include="OpenIddict.EntityFrameworkCore" Version="1.0.0-*"/> < PackageReference Include="OpenIddict.Mvc" Version="1.0.0-*"/> < DotNetCliToolReference Include="Microsoft.EntityFrameworkCore.Tools.DotNet" Version="1.0.0-msbuild3-final" /> < DotNetCliToolReference Include="Microsoft.DotNet.Watcher.Tools" Version="1.0.0-msbuild3-final"/>

Looks like issue with xunit on MacOS, same project configuration working for on Window but not on Mac OS. Mstest on Mac OS for same packages working fine.
MacOsNoDiscovery578.zip
/cc @onovotny @bradwilson

Sorry, I don't have a Mac to try this on.

FWIW, I can confirm this bug. I have a build failing on my Mac locally, but builds fine on a Linux based Jenkins box.

Mac Version: 10.12.3 (16D32)

$ dotnet 
Microsoft .NET Core Shared Framework Host

  Version  : 1.1.0
  Build    : 928f77c4bc3f49d892459992fb6e1d5542cb5e86

$ mono --version
Mono JIT compiler version 4.8.0 (mono-4.8.0-branch/8f6d0f6 Thu Mar  9 11:59:17 EST 2017)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
	TLS:           normal
	SIGSEGV:       altstack
	Notification:  kqueue
	Architecture:  x86
	Disabled:      none
	Misc:          softdebug 
	LLVM:          yes(3.6.0svn-mono-master/8b1520c)
	GC:            sgen

Will dig into it a bit deeper once I have some time.

Same problem here.
Linux works fine.
Mac can't find tests.

I am running into the same issue. Is there any known workaround for this ?

Can also confirm, mac can find tests, windows and linux can. Thanks

@rnowosielski Can you try increase max limit for number of open files per process, Eg: By adding ulimit -n 4096 to /etc/profile.

@smadala I can confirm that adding ulimit -n 4096 to /etc/profile fixed the issue for me. This is a reasonably simply workaround until the issue is fixed in xunit.

OS: OS X 10.11.6
CLI: 1.0.1 (005bd40cd1)
SDK: 1.1.0 (928f77c4bc3f49d892459992fb6e1d5542cb5e86)

/cc @bradwilson @ @onovotny
Discovery is failing with System.IO.IOException: Too many open files at
https://github.com/xunit/visualstudio.xunit/blob/2.2/xunit.runner.visualstudio.desktop/VsTestRunner.cs#L432.
This exception should be logged to testplatform.

Moved issue to xunit repo: xunit/xunit#1199

Don't forget to restart your mac if you try to do the ulimit -n 4096. Worked after!