nunit3-vs-adapter: NUnit3TestAdapter 3.15.0 fails to run test: "NUnit failed to load"

When reporting a bug, please provide the following information to speed up triage:

  • NUnit and NUnit3TestAdapter versions

Matches App.sln in repo below:

<PackageReference Include="nunit" Version="3.8.1" />
<PackageReference Include="NUnit3TestAdapter" Version="3.15.0" />
<PackageReference Include="Microsoft.NET.Test.Sdk" Version="16.2.0" />
  • Visual Studio edition and full version number (see Help About)

16.2.3

  • A short repro, preferably attached or pointing to a git repo or gist

Full reproduction https://github.com/seangwright/NUnit-Test-Adapter-Bug-Repro

App.sln is using

<PackageReference Include="nunit" Version="3.8.1" />
<PackageReference Include="NUnit3TestAdapter" Version="3.15.0" />
<PackageReference Include="Microsoft.NET.Test.Sdk" Version="16.2.0" />

App2.sln is using

<PackageReference Include="nunit" Version="3.8.1" />
<PackageReference Include="NUnit3TestAdapter" Version="3.14.0" />
<PackageReference Include="Microsoft.NET.Test.Sdk" Version="16.2.0" />

Test fails to run for NUnit3TestAdapter 3.15.0 but runs correctly for 3.14.0

  • What .net platform and version is being targeted

net472 (but with the new Common Project System / SDK style project)

  • If TFS/VSTS issue, what version, hosted, on-premises, and what build task you see this in

On-prem in Visual Studio 2019

Output Window - Tests (for 3.14.0)

[8/26/2019 6:02:11.191 PM Diagnostic] Enqueue operation 'RunSelectedOperation', hashcode:16874580 
[8/26/2019 6:02:11.192 PM Diagnostic] Operation left in the the queue: 1
[8/26/2019 6:02:11.192 PM Diagnostic] 	'RunSelectedOperation', hashcode:16874580
[8/26/2019 6:02:11.192 PM Diagnostic] 

[8/26/2019 6:02:11.192 PM Diagnostic] Operation Dequeue : 'RunSelectedOperation'
[8/26/2019 6:02:11.548 PM Diagnostic] Starting programmatic build of containers... 
[8/26/2019 6:02:11.605 PM Diagnostic] Loading Project 4b5691bb-da6f-4216-89bf-09783092ca8a [1] => 
===
Id: 4b5691bb-da6f-4216-89bf-09783092ca8a
ProjectFilePath: C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\App2.Tests.csproj
DefaultOutputPath: C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll
DefaultTargetFramework: net472
ProjectName: App2.Tests
Capabilities: UseFileGlobs,AppDesigner,AssemblyReferences,Managed,SupportAvailableItemName,FolderPublish,CPS,ProjectConfigurationsDeclaredDimensions,RelativePathDerivedDefaultNamespace,OpenProjectFile,UserSourceItems,VisualStudioWellKnownOutputGroups,TestContainer,DynamicDependentFile,NoGeneralDependentFileIcon,CSharp,SharedProjectReferences,Publish,ReferenceManagerProjects,EditAndContinue,Microsoft.VisualStudio.ProjectSystem.RetailRuntime,ReferenceManagerWinRT,AllTargetOutputGroups,SingleFileGenerators,ProjectReferences,ReferenceManagerSharedProjects,HostSetActiveProjectConfiguration,ClassDesigner,PackageReferences,GenerateDocumentationFile,AppSettings,HandlesOwnReload,RunningInVisualStudio,WinRTReferences,Pack,LaunchProfiles,ReferenceManagerCOM,LanguageService,ReferenceManagerAssemblies,ReferenceManagerBrowse,PersistDesignTimeDataOutOfProject,DependenciesTree,DeclaredSourceItems,PreserveFormatting,.NET,DataSourceWindow,OutputGroups,COMReferences
IsAppContainer: False
IsCpsProject: True
IsMiscellaneous: False
HasTestContainerCapability: True
IsCSharpOrVBProject: True

[8/26/2019 6:02:12.417 PM Diagnostic] Completed programmatic build of containers.
[8/26/2019 6:02:12.422 PM Diagnostic] TestContainer update (build) complete : 878 ms
[8/26/2019 6:02:12.524 PM Diagnostic] DiscoveryOperation<RunSelectedOperation> FinishedChangedCotainers, changed container count is 1
[8/26/2019 6:02:12.557 PM Diagnostic] Discovering the following containers :
[8/26/2019 6:02:12.557 PM Diagnostic] 	C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll
[8/26/2019 6:02:12.608 PM Informational] ---------- Discovery started ----------
[8/26/2019 6:02:12.608 PM Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettingsService 
[8/26/2019 6:02:12.608 PM Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettingsService key: VS.UnitTest.TestWindow.RunSettingsService.Name value:VSTest Run Configuration
[8/26/2019 6:02:12.608 PM Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettings 
[8/26/2019 6:02:12.608 PM Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettings key: VS.UnitTest.TestWindow.RunSettings.Services value:1
[8/26/2019 6:02:12.609 PM Diagnostic] File timestamp changed from 8/26/2019 5:52:15 PM to 8/26/2019 6:02:12 PM for C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll
[8/26/2019 6:02:12.610 PM Diagnostic] Grouped C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll : (AnyCPU, Framework45, net472, )
[8/26/2019 6:02:12.611 PM Diagnostic] Test discovery settings for C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll:
 <RunSettings>
  <RunConfiguration>
    <ResultsDirectory>C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\TestResults</ResultsDirectory>
    <SolutionDirectory>C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\</SolutionDirectory>
    <TargetPlatform>X86</TargetPlatform>
    <CollectSourceInformation>False</CollectSourceInformation>
  </RunConfiguration>
</RunSettings>.
[8/26/2019 6:02:13.309 PM Informational] NUnit Adapter 3.13.0.0: Test discovery starting
[8/26/2019 6:02:13.602 PM Informational] NUnit Adapter 3.13.0.0: Test discovery complete
[8/26/2019 6:02:13.697 PM Informational] ========== Discovery finished: 1 tests found (0:00:01.0457653) ==========
[8/26/2019 6:02:13.764 PM Informational] ---------- Run started ----------
[8/26/2019 6:02:13.790 PM Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettingsService 
[8/26/2019 6:02:13.790 PM Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettingsService key: VS.UnitTest.TestWindow.RunSettingsService.Name value:VSTest Run Configuration
[8/26/2019 6:02:13.790 PM Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettings 
[8/26/2019 6:02:13.790 PM Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettings key: VS.UnitTest.TestWindow.RunSettings.Services value:1
[8/26/2019 6:02:13.837 PM Diagnostic] Grouped C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll : (AnyCPU, Framework45, net472, )
[8/26/2019 6:02:13.868 PM Diagnostic] Tests run settings for C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll:
 <RunSettings>
  <RunConfiguration>
    <ResultsDirectory>C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\TestResults</ResultsDirectory>
    <SolutionDirectory>C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\</SolutionDirectory>
    <TargetPlatform>X86</TargetPlatform>
    <CollectSourceInformation>False</CollectSourceInformation>
  </RunConfiguration>
</RunSettings>.
[8/26/2019 6:02:14.167 PM Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[8/26/2019 6:02:14.456 PM Informational] NUnit Adapter 3.13.0.0: Test execution started
[8/26/2019 6:02:14.482 PM Informational] Running selected tests in C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll
[8/26/2019 6:02:14.580 PM Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[8/26/2019 6:02:14.749 PM Informational]    NUnit3TestExecutor converted 1 of 1 NUnit test cases
[8/26/2019 6:02:14.897 PM Informational] NUnit Adapter 3.13.0.0: Test execution complete
[8/26/2019 6:02:15.264 PM Diagnostic] Test assembly C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App2.Tests\bin\Debug\net472\App2.Tests.dll references test framework: Nunit
[8/26/2019 6:02:15.273 PM Diagnostic] Project App2.Tests references test adapter: NUnit3TestAdapter, version 3.14.0
[8/26/2019 6:02:15.277 PM Informational] ========== Run finished: 1 tests run (0:00:01.3001368) ==========
[8/26/2019 6:02:15.355 PM Diagnostic] UpdateSummary Detail Unchanged: SKIPPED

Output Window - Tests (for 3.15.0)

[8/26/2019 5:57:01.653 PM Diagnostic] Enqueue operation 'RunSelectedOperation', hashcode:32775692 
[8/26/2019 5:57:01.653 PM Diagnostic] Operation left in the the queue: 1
[8/26/2019 5:57:01.653 PM Diagnostic] 	'RunSelectedOperation', hashcode:32775692
[8/26/2019 5:57:01.653 PM Diagnostic] 

[8/26/2019 5:57:01.653 PM Diagnostic] Operation Dequeue : 'RunSelectedOperation'
[8/26/2019 5:57:01.995 PM Diagnostic] Starting programmatic build of containers... 
[8/26/2019 5:57:02.243 PM Diagnostic] Completed programmatic build of containers.
[8/26/2019 5:57:02.243 PM Diagnostic] TestContainer update (build) complete : 248 ms
[8/26/2019 5:57:02.244 PM Diagnostic] DiscoveryOperation<RunSelectedOperation> FinishedChangedCotainers, changed container count is 1
[8/26/2019 5:57:02.244 PM Diagnostic] Discovering the following containers :
[8/26/2019 5:57:02.244 PM Diagnostic] 	C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App.Tests\bin\Debug\net472\App.Tests.dll
[8/26/2019 5:57:02.249 PM Informational] ---------- Discovery started ----------
[8/26/2019 5:57:02.263 PM Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettingsService 
[8/26/2019 5:57:02.263 PM Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettingsService key: VS.UnitTest.TestWindow.RunSettingsService.Name value:VSTest Run Configuration
[8/26/2019 5:57:02.264 PM Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettings 
[8/26/2019 5:57:02.264 PM Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettings key: VS.UnitTest.TestWindow.RunSettings.Services value:1
[8/26/2019 5:57:02.264 PM Diagnostic] File timestamp remains 8/26/2019 5:49:36 PM for C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App.Tests\bin\Debug\net472\App.Tests.dll
[8/26/2019 5:57:02.264 PM Informational] ========== Discovery skipped: All test containers are up to date ==========
[8/26/2019 5:57:02.276 PM Informational] ---------- Run started ----------
[8/26/2019 5:57:02.297 PM Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettingsService 
[8/26/2019 5:57:02.298 PM Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettingsService key: VS.UnitTest.TestWindow.RunSettingsService.Name value:VSTest Run Configuration
[8/26/2019 5:57:02.298 PM Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettings 
[8/26/2019 5:57:02.298 PM Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettings key: VS.UnitTest.TestWindow.RunSettings.Services value:1
[8/26/2019 5:57:02.299 PM Diagnostic] Grouped C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App.Tests\bin\Debug\net472\App.Tests.dll : (AnyCPU, Framework45, net472, )
[8/26/2019 5:57:02.299 PM Diagnostic] Tests run settings for C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App.Tests\bin\Debug\net472\App.Tests.dll:
 <RunSettings>
  <RunConfiguration>
    <ResultsDirectory>C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\TestResults</ResultsDirectory>
    <SolutionDirectory>C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\</SolutionDirectory>
    <TargetPlatform>X86</TargetPlatform>
    <CollectSourceInformation>False</CollectSourceInformation>
  </RunConfiguration>
</RunSettings>.
[8/26/2019 5:57:02.601 PM Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[8/26/2019 5:57:02.886 PM Informational] NUnit Adapter 3.15.0.0: Test execution started
[8/26/2019 5:57:02.914 PM Informational] Running selected tests in C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App.Tests\bin\Debug\net472\App.Tests.dll
[8/26/2019 5:57:02.996 PM Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[8/26/2019 5:57:03.162 PM Informational]    NUnit failed to load C:\dev\workspace\NUnit-Test-Adapter-Bug-Repro\App.Tests\bin\Debug\net472\App.Tests.dll
[8/26/2019 5:57:03.170 PM Informational] NUnit Adapter 3.15.0.0: Test execution complete
[8/26/2019 5:57:03.284 PM Diagnostic] Project App.Tests references test adapter: NUnit3TestAdapter, version 3.15.0
[8/26/2019 5:57:03.286 PM Informational] ========== Run finished: 0 tests run (0:00:00.9445475) ==========
[8/26/2019 5:57:03.526 PM Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[8/26/2019 5:57:03.901 PM Diagnostic] UpdateSummary Detail Unchanged: SKIPPED

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Reactions: 12
  • Comments: 68 (50 by maintainers)

Most upvoted comments

FWIW, I figured out why the tests kept failing due to the timeout.

What happens is that when running the code on .NETCore3, The ThreadPool may end up filled with tasks blocked or doing NUnit work and the pool waits 500ms before creating a new worker thread. Some tests use code that execute Task.Run which would then wait multiples of 500 milliseconds to get running so they randomly timeout on my 4 core machine (no HT).

Yes, that is so. But they need to publish it, I just wonder if the maintainers are still around.
@jnm2 just told me the breaking change is at version 3.9. See comment higher up: https://github.com/nunit/nunit3-vs-adapter/issues/648#issuecomment-526252599

@seangwright 3.15.1 hotfix released now.

Unfortunately when we made test properties read-only, we discussed source-breaking changes (and decided they would be rare and went ahead in spite of them) but we did not think about binary-breaking changes.

The .NET runtime and ECMA spec no longer recognizes a method as the same method if the return type changes to a new type that is not assignable to the old type. Some languages overload calls on return type.

There aren’t tools out there to help remind us when we miss things, so this is just too bad. The complexity of both source- and binary-breaking changes is so high that I’m going to advocate waiting for v4 if anything else comes up so that users and library developers can plan and reason around our releases with fewer pitfalls. Kentico will need to recompile against NUnit 3.9 and set the version range to a minimum of NUnit 3.9.

@jnm2 I think it’s a bug in the framework and possibly also NUnitLite. NUnitLite defaults to generating a pre-filter based on the run filter that is passed in. I can’t remember, but it might have the same bug.

So that would be a framework fix too? If we fix that in e.g. Framework 3.12.1, then the only options I can think of right now are:

  1. Tell people that Adapter 3.15 is only compatible with Framework 3.12.1 due to bugs in all the Framework versions prior
  2. Stop using the prefilter entirely, or make it opt-in via runsettings. Opt-out seems less good due to the three vectors of bugs.
  3. Implement some feature in the engine so that the prefilter is passed to the framework if and only if the framework version is >= 3.12.1. Might take a while, so we should probably choose 1 or 2 for the time being?

@seangwright and others: NUnit Framework versions lower than 3.11 were broken this way all along. You couldn’t see it before because you weren’t using a runner that exercised NUnit Framework this way until you updated to Test Adapter 3.15. What kind of difficulties would you face if you upgraded to NUnit Framework 3.11 or 3.12?

Acceptance test: Yeah. We need to create a test harness that executes that other interface, simulating calling it from VS.

@jnm2 That will work because you’re then running All Tests. That is a seperate method being called. You need to go into the Test Explorer in Visual Studio and select some tests, that is what really breaks it - and also triggers the pre-filter. The pre-filter doesn’t work for any command line case.

Seeing the same when trying to launch Selenium GUI tests on Visual Studio 2019 (16.2.3) (building for net462) using adapter version 3.15; reverting to 3.14 resolves the problem locally. 3.15 also does not seem to function on Azure DevOps, I have found the following error on the build pipelines output:

NUnit Adapter 3.15.0.0: Test execution complete
No test is available

It seems like the test adapter is not locating the test cases.

InternalTrace: Initializing at level Debug
11:01:21.528 Debug [12] DefaultTestAssemblyBuilder: Loading C:\Repos\example\Project\bin\Debug\xyz.dll in AppDomain domain-9c416945-Project.dll
11:01:21.552 Debug [12] DefaultTestAssemblyBuilder: Examining assembly for test fixtures
11:01:21.645 Debug [12] DefaultTestAssemblyBuilder: Found 1 classes to examine
11:01:21.683 Debug [12] DefaultTestAssemblyBuilder: Found 1 fixtures with 0 test cases
11:01:21.811 Info  [12] DefaultTestAssemblyRunner: Running tests

Example test case from my framework:

[TestCase(UsernameKeys.Sales, TestName = "ABC")]
[Description("This will test ABC.")]
[Category("Regression Test Pack")]
[Retry(2)]
public void Test_Case_ABC(UsernameKeys userKey)
{
	Assert.That(() =>
	{
		//start test

		
	}, Throws.Nothing);
}