Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

NUnit3TestAdapter 3.15.0 fails to run test: "NUnit failed to load" #648

Closed
seangwright opened this issue Aug 26, 2019 · 68 comments
Closed
Labels
closed:done is:bug resolution:known We have a resolution for this, which is described in the issue, under heading Resolution
Milestone

Comments

@seangwright
Copy link

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
@BVisagie
Copy link

BVisagie commented Aug 27, 2019

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);
}

@OsirisTerje
Copy link
Member

@seangwright I see you use NUnit 3.8. If I update to NUnit 3.12 it works for me.
@BVisagie This is hard to say, need a repro to confirm.

@seangwright
Copy link
Author

@OsirisTerje that is correct - explicitly version 3.8.1.

The CMS I am writing tests for, Kentico, takes a hard dependency on that version and if I use another version then the tests do not work.

All that said, is it the case that 3.15.0 of NUnit3TestAdapter requires a version of NUnit > 3.8.1?

If that is so, should it be in the NuGet package definition of NUnit3TestAdapter?

@OsirisTerje
Copy link
Member

OsirisTerje commented Aug 28, 2019

@seangwright There is no explicit requirement about that, so I am bit surprised by why this pops up with 3.15.

May I ask what exactly fails when you try a higher version than 3.8.1 ?

@Siko91
Copy link

Siko91 commented Aug 28, 2019

Most people in my team have this problem as well.
We use NUnit 3.10 and NUnit3TestAdapter 3.15
With VS2017, when trying to run or debug a test, half of the attempts would end up with this error.
The other half of the attempts successfully start running/debugging the test.

It fails with this error on every second attempt.
Accurate like a clock.

first time running a test starts properly
second tome - NUnit failed to load
third time starts properly
fourth time - failed to load
and so on...

I am guessing that the run that starts properly changes some persisting state (file?) and sets it in an invalid way, so that the next one can't start, but can reset the state... so that the next one can start and screw it up again.

I hope this helps narrow down the possible problem.

@Yourikahn
Copy link

Yourikahn commented Aug 28, 2019

Same issue in my team with NUnit 3.9 and Visual studio 2015 (NUnit3TestAdapter 3.15)
We can run unit test with RunAll button, but failed to load dll from selected test.

Internal trace I got:

RunAll test:
InternalTrace: Initializing at level Debug 15:56:36.333 Debug [16] DefaultTestAssemblyBuilder: Loading C:\...\MTDWRServices.Test.dll in AppDomain domain-1ee0f9a4-MTDWRServices.Test.dll 15:56:36.344 Debug [16] DefaultTestAssemblyBuilder: Examining assembly for test fixtures 15:56:36.358 Debug [16] DefaultTestAssemblyBuilder: Found 422 classes to examine 15:56:36.511 Debug [16] DefaultTestAssemblyBuilder: Found 46 fixtures with 1544 test cases

one Unit Test:
InternalTrace: Initializing at level Debug 16:40:32.401 Debug [11] DefaultTestAssemblyBuilder: Loading C:\...\MTDWRServices.Test.dll in AppDomain domain-1ee0f9a4-MTDWRServices.Test.dll 16:40:32.476 Debug [11] DefaultTestAssemblyBuilder: Examining assembly for test fixtures 16:40:32.525 Debug [11] DefaultTestAssemblyBuilder: Found 0 classes to examine 16:40:32.525 Debug [11] DefaultTestAssemblyBuilder: Found 0 fixtures with 0 test cases
And then:
Running selected tests in C:\...\MTDWRServices.Test.dll Test Output folder checked/created : C:\...\Dump NUnit failed to load C:\...\MTDWRServices.Test.dll NUnit Adapter 3.15.0.0: Test execution complete

Hope this point help!

Edit: Switch to NUnit 3.12 fix the issue

@OsirisTerje
Copy link
Member

@jnm2 When I enable verbosity, I see that when using NUnit 3.8.1 it fails to load the dll.
" NUnit failed to load D:\repos\nunit\issues\issue648\NUnit-Test-Adapter-Bug-Repro\App.Tests\bin\Debug\net472\App.Tests.dll
[28.08.2019 7:06:00.037 Informational] "
It loads in NUnit 3.12, and it loads using NUnit3TestAdapter 3.14. Any ideas ?

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

I cloned https://github.com/seangwright/NUnit-Test-Adapter-Bug-Repro and ran dotnet test App.sln and dotnet test App2.sln, so the dotnet-CLI-packaged version of VSTest is using our adapter fine?

Test run for C:\Users\Joseph\Source\Repos\NUnit-Test-Adapter-Bug-Repro\App.Tests\bin\Debug\net472\App.Tests.dll(.NETFramework,Version=v4.7.2)
Microsoft (R) Test Execution Command Line Tool Version 16.3.0-preview-20190715-02
Copyright (c) Microsoft Corporation.  All rights reserved.

Starting test execution, please wait...

Test Run Successful.
Total tests: 1
     Passed: 1
 Total time: 0.6561 Seconds

So this is a problem only with a specific version of VSTest perhaps?

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

Running using Test Explorer in VS 16.3 Preview 2 reproduces the problem, so there is some difference between VS and the dotnet CLI.

@OsirisTerje
Copy link
Member

@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.

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

Ah, so we can't write an acceptance test currently because the bug can only happen with live Visual Studio UI.

@OsirisTerje
Copy link
Member

I noticed one issue where they reported it also didn't work for Azure Pipeline builds, which uses the command line, but I can't see how that can be. Nothing is changed, so I think that is a fluke. Until some more people reports the same. All the rest of the issues are about this particular case with the pre-filter. This case here is weird though.....But it may point to something....

@OsirisTerje
Copy link
Member

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

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

I wonder if there was a bug present in NUnit framework 3.8 that we're triggering, since it is the one failing to load the assembly.

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

NUnit Framework 3.11.0 repros, 3.12.0 works. Looking at which commit now.

@OsirisTerje
Copy link
Member

OsirisTerje commented Aug 28, 2019

Ok, so :
| NUnit | Adapter | Result |
| <=3.11 | 3.15 | fail |
| 3,12 | 3.15 or 3.14 | works |
| <=3.11 | 3.14 | works |

That must mean there is something between 3.14 adapter and 3.15 that drags in something wrong ?

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

If it's an NUnit framework bug triggered by passing the framework a prefilter, the adapter should do a version check—or just say too bad, update to a non-buggy framework version. If it's an adapter bug, we can work on a fix in this repo. There's also the engine. Let's find out.

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

My methodology was bad. I needed an extra rebuild step for some reason.
NUnit 3.11.0 does not repro, but NUnit 3.10.1 does. NUnit 3.11.0 was when the framework first started applying the prefilter.

@OsirisTerje
Copy link
Member

OsirisTerje commented Aug 28, 2019

Yes, that would work for this issue, but we also have the two other bugs, the one which makes this prefilter ignore anything with SetupFIxture #649 , the other that makes it not work with custom TestCaseSources #650. That doesnt seem to be dependent upon the framework version.

About the prefilter implementation we absolutely need to add the version check. How is that done through the engine ?

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

About the prefilter implementation we absolutely need to add the version check. How is that done through the engine ?

I'm not sure that it is possible without an engine change.

This is the commit where NUnit stops failing to load the test assembly when a prefilter is specified: nunit/nunit@d09def3, the merge of nunit/nunit#2878. It's tempting to say that Charlie fixed an actual longstanding bug where NUnit misbehaved rather than ignoring the prefilter if a prefilter was given, but we obviously need to look at everything.

@OsirisTerje
Copy link
Member

Note the runner is created AFTER the pre-filter is created. So it seems it should really be in the engine. This should also be done per assembly, since they may exist with different frameworks, even if that is kind of "stupid". So, do we know the framework version before we call it ? Got a feeling it will be happening too late.

@OsirisTerje
Copy link
Member

We could use a feature flag in the runsettings for this case, that is, where the nunit is a lower version that we now support. It is a special case.

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

I *think* this is the bugfix commit within @CharliePoole's PR that would have fixed this: "Added tests of pre-filtering, which didn't have them before; fixed bug where filter would add a fixture twice"
nunit/nunit@54015aa The test shows that loading would fail.
(I say I think because my clone of the repo doesn't have this commit for some reason.)

If this is the bugfix, the bug has already been fixed in NUnit Framework 3.11. If it was any other bug that was not the fault of the adapter, we would tell folks to update.

Is this case special enough to warrant disabling sending the prefilter to any version of NUnit Framework, since we don't have a way to tell them apart? Does it warrant a runsettings flag to opt out of prefiltering if you can't update to 3.11+ for some reason?

@jnm2
Copy link
Contributor

jnm2 commented Aug 28, 2019

@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?

@OsirisTerje
Copy link
Member

@jnm2 Have you also had a look at the two other issues? They are correct versions, but still failing. The SetupFixture is the one I am really curious about, the other is probably the way the prefilter is set up that makes it not match the FQN.

@OsirisTerje OsirisTerje added is:bug resolution:known We have a resolution for this, which is described in the issue, under heading Resolution labels Aug 28, 2019
@OsirisTerje OsirisTerje added this to the 3.15.1 milestone Aug 28, 2019
@jnm2
Copy link
Contributor

jnm2 commented Aug 29, 2019

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.

@OsirisTerje
Copy link
Member

@seangwright There is now a beta version of the fix in https://www.myget.org/feed/nunit/package/nuget/NUnit3TestAdapter/3.15.1-dev-01134 . Would appreciate if you checked it.

@OsirisTerje
Copy link
Member

@seangwright 3.15.1 hotfix released now.

@akarnokd
Copy link

Hi. I'm having the same problem with 3.15.1 in this project.

Visual Studio Community 16.3.9, Windows 10 x64 1809. NUnit 3.12.

The Test Explorer window is populated but neither a specific nor all tests run. I did play with the X86 and X64 config to no avail.

[2019. 11. 15. 1:20:04.688 de. Diagnostic] Enqueue operation 'RunAllOperation', hashcode:36562506 
[2019. 11. 15. 1:20:04.688 de. Diagnostic] Operation left in the the queue: 1
[2019. 11. 15. 1:20:04.688 de. Diagnostic] 	'RunAllOperation', hashcode:36562506
[2019. 11. 15. 1:20:04.688 de. Diagnostic] 

[2019. 11. 15. 1:20:04.689 de. Diagnostic] Operation Dequeue : 'RunAllOperation'
[2019. 11. 15. 1:20:04.737 de. Diagnostic] Starting programmatic build of containers... 
[2019. 11. 15. 1:20:04.847 de. Diagnostic] Completed programmatic build of containers.
[2019. 11. 15. 1:20:04.847 de. Diagnostic] TestContainer update (build) complete : 109 ms
[2019. 11. 15. 1:20:04.849 de. Diagnostic] test container discoverer executor://projectoutputcontainerdiscoverer/v1, discovered 2 containers
[2019. 11. 15. 1:20:04.849 de. Diagnostic] Containers from 'Microsoft.VisualStudio.TestWindow.Client.TestContainer.ProjectOutputContainerDiscoverer' :
[2019. 11. 15. 1:20:04.849 de. Diagnostic] 	C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET\bin\Debug\Reactive4.NET.dll
[2019. 11. 15. 1:20:04.849 de. Diagnostic] 	C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET.Test\bin\Debug\Reactive4.NET.Test.dll
[2019. 11. 15. 1:20:04.976 de. Diagnostic] test container discoverer executor://orderedtestadapter/v1, discovered 0 containers
[2019. 11. 15. 1:20:04.976 de. Diagnostic] No containers found from 'Microsoft.VisualStudio.MSTest.TestWindow.OrderedTestContainerDiscoverer' :
[2019. 11. 15. 1:20:05.019 de. Diagnostic] test container discoverer executor://generictestadapter/v1, discovered 0 containers
[2019. 11. 15. 1:20:05.020 de. Diagnostic] No containers found from 'Microsoft.VisualStudio.MSTest.TestWindow.GenericTestContainerDiscoverer' :
[2019. 11. 15. 1:20:05.237 de. Diagnostic] test container discoverer executor://webtestadapter/v1, discovered 0 containers
[2019. 11. 15. 1:20:05.237 de. Diagnostic] No containers found from 'Microsoft.VisualStudio.MSTest.TestWindow.WebTestContainerDiscoverer' :
[2019. 11. 15. 1:20:05.238 de. Diagnostic] DiscoveryOperation<RunAllOperation> FinishedChangedCotainers, changed container count is 2
[2019. 11. 15. 1:20:05.238 de. Diagnostic] Discovering the following containers :
[2019. 11. 15. 1:20:05.238 de. Diagnostic] 	C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET.Test\bin\Debug\Reactive4.NET.Test.dll
[2019. 11. 15. 1:20:05.238 de. Diagnostic] 	C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET\bin\Debug\Reactive4.NET.dll
[2019. 11. 15. 1:20:05.310 de. Informational] ---------- Discovery started ----------
[2019. 11. 15. 1:20:05.414 de. Diagnostic] Project Reactive4.NET.Test references test adapter: NUnit3TestAdapter, version 3.15.1
[2019. 11. 15. 1:20:05.453 de. Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettingsService 
[2019. 11. 15. 1:20:05.453 de. Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettingsService key: VS.UnitTest.TestWindow.RunSettingsService.Name value:VSTest Run Configuration
[2019. 11. 15. 1:20:05.453 de. Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettings 
[2019. 11. 15. 1:20:05.453 de. Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettings key: VS.UnitTest.TestWindow.RunSettings.Services value:1
[2019. 11. 15. 1:20:05.454 de. Diagnostic] File timestamp remains 2019. 11. 15. 1:10:12 for C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET.Test\bin\Debug\Reactive4.NET.Test.dll
[2019. 11. 15. 1:20:05.454 de. Informational] ========== Discovery skipped: All test containers are up to date ==========
[2019. 11. 15. 1:20:05.454 de. Diagnostic] File timestamp remains 2019. 11. 15. 1:10:12 for C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET\bin\Debug\Reactive4.NET.dll
[2019. 11. 15. 1:20:05.564 de. Informational] ---------- Run started ----------
[2019. 11. 15. 1:20:05.565 de. Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettingsService 
[2019. 11. 15. 1:20:05.565 de. Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettingsService key: VS.UnitTest.TestWindow.RunSettingsService.Name value:VSTest Run Configuration
[2019. 11. 15. 1:20:05.565 de. Diagnostic] TelemetrySession: Creating the event: VS/UnitTest/TestWindow/Ext/RunSettings 
[2019. 11. 15. 1:20:05.565 de. Diagnostic] Event:VS/UnitTest/TestWindow/Ext/RunSettings key: VS.UnitTest.TestWindow.RunSettings.Services value:1
[2019. 11. 15. 1:20:05.579 de. Diagnostic] Grouped C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET.Test\bin\Debug\Reactive4.NET.Test.dll : (X64, Framework45, net452, )
[2019. 11. 15. 1:20:06.068 de. Diagnostic] Some tests from the test run selection do not have origin VSTestAdapterDiscovery and will be executed by name.
[2019. 11. 15. 1:20:06.689 de. Diagnostic] Some tests from the test run selection do not have origin VSTestAdapterDiscovery and will be executed by name.
[2019. 11. 15. 1:20:07.040 de. Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[2019. 11. 15. 1:20:07.450 de. Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[2019. 11. 15. 1:20:07.861 de. Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[2019. 11. 15. 1:20:08.138 de. Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[2019. 11. 15. 1:20:08.315 de. Diagnostic] Some tests from the test run selection do not have origin VSTestAdapterDiscovery and will be executed by name.
[2019. 11. 15. 1:20:08.315 de. Diagnostic] Tests run settings for C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET.Test\bin\Debug\Reactive4.NET.Test.dll:
 <RunSettings>
  <RunConfiguration>
    <ResultsDirectory>C:\Users\akarnokd\git\Reactive4.NET\TestResults</ResultsDirectory>
    <SolutionDirectory>C:\Users\akarnokd\git\Reactive4.NET\</SolutionDirectory>
    <TargetPlatform>X64</TargetPlatform>
    <CollectSourceInformation>False</CollectSourceInformation>
  </RunConfiguration>
</RunSettings>.
[2019. 11. 15. 1:20:08.403 de. Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[2019. 11. 15. 1:20:08.856 de. Informational] Logging TestHost Diagnostics in file: C:\Users\akarnokd\AppData\Local\Temp\TestPlatformLogs\6644_11_15_2019_01_17_38\logs.host.19-11-15_01-20-08_41858_8.txt
[2019. 11. 15. 1:20:09.473 de. Informational] NUnit Adapter 3.15.1.0: Test execution started
[2019. 11. 15. 1:20:09.487 de. Informational] Running all tests in C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET.Test\bin\Debug\Reactive4.NET.Test.dll
[2019. 11. 15. 1:20:09.899 de. Informational]    NUnit failed to load C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET.Test\bin\Debug\Reactive4.NET.Test.dll
[2019. 11. 15. 1:20:09.905 de. Informational] NUnit Adapter 3.15.1.0: Test execution complete
[2019. 11. 15. 1:20:09.915 de. Warning] No test matches the given testcase filter `FullyQualifiedName=Reactive4.NET.Test.ArrayQueueTest.Normal|FullyQualifiedName=Reactive4.NET.Test.AsyncProcessor1Tck.Optional_spec104_mustSignalOnErrorWhenFails|FullyQualifiedName=Reactive4.NET.Test.AsyncProcessor1Tck.Optional_spec105_emptyStreamMustTermin...` in C:\Users\akarnokd\git\Reactive4.NET\Reactive4.NET.Test\bin\Debug\Reactive4.NET.Test.dll
[2019. 11. 15. 1:20:10.092 de. Diagnostic] UpdateSummary Detail Unchanged: SKIPPED
[2019. 11. 15. 1:20:10.263 de. Informational] ========== Run finished: 0 tests run (0:00:04,6826326) ==========
[2019. 11. 15. 1:20:10.348 de. Diagnostic] UpdateSummary Detail Unchanged: SKIPPED

@OsirisTerje
Copy link
Member

OsirisTerje commented Nov 15, 2019

@akarnokd I can confirm this behavior, but it is caused by the underlying Reactive.Streams.tck package which has a dependency on NUnit 3.6.1, and has hardwired that pretty much into their package. I made my own version of, where I upgraded to 3.12, and then it all worked fine.
image

(You have an huge amount of tests, and some of them are really slow, btw. )

And, you had a binding to 3.6.1 too, in your test projects app.config. Remove that one.

@akarnokd
Copy link

Thanks for the info (I have very limited understanding of the .NET ecosystem unfortunately). The TCK specifies NUnit >= 3.6.1, shouldn't that automatically work with 3.12 given the target 4.5.2 supposedly does auto-redirect? Is it possible to workaround this in my project or does the TCK project have to release a newer version?

@OsirisTerje
Copy link
Member

The TCK project has to be updated, but I see it seems rarely updated. I can fork it and add my changes there and raise a PR to them.
There is some breaking change somewhere in the range from 3.6 to 3.12. I noted your project tried to downgrade using the binding redirects. That is not a good way, it is better to directly specify you want to run the 3.6.1. Anyway, it just might run if you downgrade your project to 3.6.1, but I am not sure.
(PS: I have asked the other NUnit core guys if we have the exact point somewhere about the breaking change. ).

@akarnokd
Copy link

Thanks @OsirisTerje, that would be great! (I suppose one only needs to change the NUnit dependency versions all around the subprojects, right?)

@OsirisTerje
Copy link
Member

OsirisTerje commented Nov 15, 2019

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: #648 (comment)

@akarnokd
Copy link

I'm not sure about the maintainers. It is supposed to be the standard library & TCK for .NET so taking bits of it for my project wouldn't be interoperable.

I meant to post a PR regarding NetCore3 support where I now had to upgrade the NUnit anyway (reactive-streams/reactive-streams-dotnet#46). The problem is, RS.NET now fails its own verification test with NUnit 3.12 and I have no idea how or why.

@OsirisTerje
Copy link
Member

@akarnokd Was just about to raise the PR when I noted you already had done so. Hope they accept that you do two things in one PR.
You can link to this issue: reactive-streams/reactive-streams-dotnet#47

@OsirisTerje
Copy link
Member

I see the same errors I assume in my fork.
There are several tests failing, but the code is not that easy to understand, so I think this has to be up to the maintainers. I can't see anything related to upgrading NUnit here, but there can be they do in fact have something related.

@akarnokd
Copy link

Some failures are due to these:

try
{
    Assert.Fail(message, exception);
}
catch (Exception)
{
    AsyncErrors.Enqueue(exception);
}

As I understand it, in NUnit 3.6, Assert.Fail would throw and the exception would get suppressed. In newer NUnit, the framework remembers Fail so even if the test passes otherwise, the end result is still a test failure.

@OsirisTerje
Copy link
Member

OsirisTerje commented Nov 15, 2019

That's a very good point.

And why is the code written that way?

It is better just to create a new exception with the given message and use that

@akarnokd
Copy link

No idea.

@OsirisTerje
Copy link
Member

And there seems to be tests that are designed to fail, calling the FlopAndFail.
I don't understand this code at all.


They seem to expect certain exceptions..... And have then relied on the implementation of NUnit asserts. Very messy.....

@akarnokd
Copy link

It is a test compatibility kit to verify 3rd party implementations honor a specification by providing NUnit test templates prepared with behavior. However, one must test the TCK itself to know it fails when it should fail, hence triggering a failure mode and then checking if the right AssertionExceptions are thrown.

@OsirisTerje
Copy link
Member

OsirisTerje commented Nov 15, 2019

Ok, but then they should just queue up the AssertionExceptions themselves, and not rely on the Assert methods. What they do now is a very indirect way of achieving this.
And it breaks.....

@OsirisTerje
Copy link
Member

OsirisTerje commented Nov 15, 2019

I started out with 55 failed tests. After replacing the Asserts with AssertionExceptions I am down to 15 failed tests.
Those tests fails due to errors in the sequences they check, mismatched messages, and so on.....
And it seems that FlopAndFail is not expected to fail either.... As you said, they expect to roll back the error. They are misusing the NUnit assertion functionality. They should have made their own failure system, and checked for that instead.

@akarnokd
Copy link

I've been working on the tests myself on that PR. Most test now pass except 3-5 that timeout when the entire class is run but not when the individual tests run. I don't understand why would the particular test case timeout after 500, 1000, 2000 milliseconds but work with 3000 milliseconds. As if Task.Run would need more than two seconds to spin up and do a trivial notification.

@OsirisTerje
Copy link
Member

I notice there are multiple Thread.Sleep calls in some methods. Can it be related to those?

@akarnokd
Copy link

No. Those wait for things not to happen. For example, the source didn't signal an item within 1 second. The failures I'm debugging is that the source should have signaled an item within 1 second yet it didn't.

@OsirisTerje
Copy link
Member

I see. Anyway good that you are down to 3-5. That means you have a fix for the ones I have left, so I'll leave this project all to you :-)

For anyone who wants to look, the repo @akarnokd is fixing is : https://github.com/reactive-streams/reactive-streams-dotnet

@akarnokd
Copy link

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).

@drvic10k
Copy link

I am experiencing the issue with NUnit 3.12 and NUnit3TestAdapter 3.15.1

DistributedTests: Test run is aborted. Logging details of the run logs.
DistributedTests: New test run created.
Test Run queued for Project Collection Build Service (Products).
DistributedTests: Test discovery started.
DistributedTests: Test Run Discovery Aborted . Test run id : 55716
DistributedTests: Unexpected error occurred during test execution. Try again.
DistributedTests: Error : NUnit Adapter 3.15.1.0: Test discovery complete
DistributedTests: Test run aborted. Test run id: 55716
System.Exception: The test run was aborted, failing the task.
PowerShell script completed with 1 errors.

it's possible that my issue is different, because for me it only works with adapter version 3.7, that is that last one that had Tools folder in the package
we are using this suggestion to deploy the adapter on the target machine: https://stackoverflow.com/questions/36622707/error-while-executing-run-functional-test-task-in-vsts

@OsirisTerje
Copy link
Member

@drvic10k First, please raise new issues, don't add to a closed one. You should not need to add any binaries at the target at all, just the nuget package. Please also add a repro solution if you want us to have a more close look at your issue.

@drvic10k
Copy link

@OsirisTerje sorry, I didn't realize it was closed
I will try to gather enough info to crate a separate issue

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
closed:done is:bug resolution:known We have a resolution for this, which is described in the issue, under heading Resolution
Projects
None yet
Development

No branches or pull requests

10 participants