@greg73 commented on Mon Jul 25 2016
Hi,
We have installed NUnit 3.4.1 on our build server (Windows 2008 R2) running Jenkins.
Randomly the console runner fails to start with the following error. After an error, if the build is re-run manually the console runner works correctly without error.
The stack trace is
System.Exception: Unable to acquire remote process agent
at NUnit.Engine.Runners.ProcessRunner.LoadPackage()
at NUnit.Engine.Runners.AbstractTestRunner.Load()
at NUnit.Engine.Runners.AggregatingTestRunner.LoadPackage()
at NUnit.Engine.Runners.AbstractTestRunner.Load()
at NUnit.Engine.Runners.MasterTestRunner.LoadPackage()
at NUnit.Engine.Runners.AbstractTestRunner.EnsurePackageIsLoaded()
at NUnit.Engine.Runners.MasterTestRunner.NUnit.Engine.ITestRunner.Run(ITestEventListener listener, TestFilter filter)
at NUnit.ConsoleRunner.ConsoleRunner.RunTests(TestPackage package, TestFilter filter)
at NUnit.ConsoleRunner.Program.Main(String[] args)
The command line we are using is
"C:\Program Files (x86)\NUnit.org\nunit-console\nunit3-console.exe" [paths to test dlls] --result:nunit-result.xml;format=nunit2
Thanks
@greg73 commented on Tue Jul 26 2016
I have now confirmed that the same error occurs when running from the command prompt. Immediately re-entering the same command results in the tests running successfully.
@CharliePoole commented on Sun Aug 07 2016
The only answer I can see is that the process runner times out. Are you using a large number of test assemblies?
@greg73 commented on Mon Aug 08 2016
No, this is quite a small project, only 3 test assemblies
@MistyKuu commented on Thu Aug 11 2016
Having the same issue on TeamCity
@rprouse commented on Mon Oct 24 2016
@greg73 and @MistyKuu, we will need more information to move forward with this issue.
@greg73 commented on Tue Oct 25 2016
@rprouse
The error is not reproducible, i.e. it will happen once and then when immediately running the same tests again the error won't happen. I think it may be related to available memory, if the server is swapping memory and the build is running slowly the error seems more likely to happen.
@CharliePoole commented on Tue Oct 25 2016
Not sure if we will be able to fix this, but moving it to the right project anyway. 馃槃
I am also seeing this with NUnit.Console 3.4.1, installed via nuget as part of our Bamboo build process.
The NUnit packages installed in the packages folder are:
25/08/2016 04:35 p.m. <DIR> NUnit.3.4.1
25/08/2016 04:35 p.m. <DIR> NUnit.Console.3.4.1
25/08/2016 04:35 p.m. <DIR> NUnit.ConsoleRunner.3.4.1
25/08/2016 04:35 p.m. <DIR> NUnit.Extension.NUnitProjectLoader.3.4.1
25/08/2016 04:35 p.m. <DIR> NUnit.Extension.NUnitV2Driver.3.4.1
25/08/2016 04:35 p.m. <DIR> NUnit.Extension.NUnitV2ResultWriter.3.4.1
25/08/2016 04:35 p.m. <DIR> NUnit.Extension.TeamCityEventListener.1.0.1
25/08/2016 04:35 p.m. <DIR> NUnit.Extension.VSProjectLoader.3.4.1
The command line executed is:
packages\NUnit.ConsoleRunner.3.4.1\tools\nunit3-console.exe OurProjectName.Tests\bin\Release\OurProjectName.Tests.dll "--result:TestResults.xml";format=nunit2
And the error reported is:
System.Exception: Unable to acquire remote process agent
at NUnit.Engine.Runners.ProcessRunner.CreateAgentAndRunner()
at NUnit.Engine.Runners.ProcessRunner.LoadPackage()
at NUnit.Engine.Runners.AbstractTestRunner.Load()
at NUnit.Engine.Runners.MasterTestRunner.LoadPackage()
at NUnit.Engine.TestEngine.GetRunner(TestPackage package)
at NUnit.ConsoleRunner.ConsoleRunner.RunTests(TestPackage package, TestFilter filter)
at NUnit.ConsoleRunner.ConsoleRunner.Execute()
at NUnit.ConsoleRunner.Program.Main(String[] args)
I'm also getting below error when I don't provide the path of nunit, something like below.
[exec] Run Environment: NCOVER_USING_PROJECT[6471E3B9202D8311D439C110FAF65D996658CBDB]
[11:23:21][exec] Run Environment: NCOVER_BUILD_ID[17.1.0_CI_308]
[11:23:21][exec] Run Environment: COR_ENABLE_PROFILING[1]
[11:23:21][exec] Run Environment: COR_PROFILER[NCover.ProfilerLauncher]
[11:23:21][exec] Unable to start requested process: nunit3-console.exe
[11:23:22][exec] EXCEPTION: 2016-12-14T11:23:21 Error starting process: --> System.ComponentModel.Win32Exception: The system cannot find the file specified
[11:23:22][exec] at System.Diagnostics.Process.StartWithCreateProcess(ProcessStartInfo startInfo)
[11:23:22][exec] at ? .???.??(String[] ? , ? ? )
Script used in nant that ran through team city.
From command line above script works fine.
I have tried below approach to fix, but it fails with different error now.
Error in command line
image
[exec]
[exec] Time Elapsed 00:00:04.06
[exec] Starting 'C:\Program Files\NCover Code Central\ncover (run --project=""UnitTests"" --build-id=17.1.0_CI_309 -- ""C:\TeamCity\buildAgent\work\GIT_Security\source\Tools\Nunit\nunit-console\nunit3-console.exe"" HostAnalytics.Pl
ln /out:TestResult.txt)' in 'C:\TeamCity\buildAgent\work\GIT_Security\source\UnitTesting\Tests\Tests'
[exec] NCover v5.5.3543.583 x64 (Administrator)
[exec] Copyright (c) 2007 - 2016 NCover LLC
[exec] Starting: NCover Code Central on Microsoft Windows NT 6.1.7601 Service Pack 1
[exec] Server Root: http://127.0.0.1:11235
[exec] Run Environment: NCOVER_USING_PROJECT[6471E3B9202D8311D439C110FAF65D996658CBDB]
[exec] Run Environment: NCOVER_BUILD_ID[17.1.0_CI_309]
[exec] Run Environment: COR_ENABLE_PROFILING[1]
[exec] Run Environment: COR_PROFILER[NCover.ProfilerLauncher]
[exec] NUnit Console Runner 3.4.1
[exec] Copyright (C) 2016 Charlie Poole
[exec]
[exec] Runtime Environment
[exec] OS Version: Microsoft Windows NT 6.1.7601 Service Pack 1
[exec] CLR Version: 4.0.30319.34209
[exec]
[exec] Test Files
[exec] HostAnalytics.Planning.Tests.sln
[exec]
[exec] System.Exception: Unable to acquire remote process agent
[exec] at NUnit.Engine.Runners.ProcessRunner.CreateAgentAndRunner()
[exec] at NUnit.Engine.Runners.ProcessRunner.LoadPackage()
[exec] at NUnit.Engine.Runners.AbstractTestRunner.Load()
[exec] at NUnit.Engine.Runners.MasterTestRunner.LoadPackage()
[exec] at NUnit.Engine.TestEngine.GetRunner(TestPackage package)
[exec] at NUnit.ConsoleRunner.ConsoleRunner.RunTests(TestPackage package, TestFilter filter)
[exec] at NUnit.ConsoleRunner.ConsoleRunner.Execute()
[exec] at NUnit.ConsoleRunner.Program.Main(String[] args)
Total time: 38.8 seconds.
The 3.5 Console Runner and Engine have been released since this issue was filed. Various fixes were made so it makes sense to try that version to see if your problem recurs.
Thanks Charlie it works fine with 3.5 ConsoleRunner. Appreciate your help!!
I don't think the update has resolved it
NUnit Console Runner 3.5.0
Copyright (C) 2016 Charlie Poole
Runtime Environment
OS Version: Microsoft Windows NT 6.1.7601 Service Pack 1
CLR Version: 4.0.30319.42000
Test Files
1.dll
2.dll
3.dll
System.Exception: Unable to acquire remote process agent
at NUnit.Engine.Runners.ProcessRunner.CreateAgentAndRunner()
at NUnit.Engine.Runners.ProcessRunner.LoadPackage()
at NUnit.Engine.Runners.AbstractTestRunner.Load()
at NUnit.Engine.Runners.AggregatingTestRunner.LoadPackage()
at NUnit.Engine.Runners.AbstractTestRunner.Load()
at NUnit.Engine.Runners.MasterTestRunner.LoadPackage()
at NUnit.Engine.TestEngine.GetRunner(TestPackage package)
at NUnit.ConsoleRunner.ConsoleRunner.RunTests(TestPackage package, TestFilter filter)
at NUnit.ConsoleRunner.Program.Main(String[] args)
@greg73 As sometimes happens, the same error message is likely arising for different reasons.
When running tests in a different process, the engine launches the process and waits for it to initialize itself and then contact the engine for work to be done. If no contact is made within a certain amount of time, then the exception you see is thrown. There is no information available to the engine as to why this happened.
At this point, I suggest using the --trace option to get an internal trace log. You will want to look at the log file for the agent that never called back.
@CharliePoole Thanks for the suggestion, I have now got a trace log
I can see there is a 30 second timeout and there seems to be a delay in ExtensionService
InternalTrace
...
11:51:58.180 Info [ 1] ProcessRunner: Loading 1.dll
11:51:58.192 Info [ 1] TestAgency: Getting standard agent for use under net-4.5
11:51:58.193 Debug [ 1] TestAgency: Using nunit-agent at C:\Program Files (x86)\NUnit.org\nunit-console\nunit-agent.exe
11:51:58.199 Debug [ 1] TestAgency: Launched Agent process 72016 - see nunit-agent_72016.log
11:51:58.199 Debug [ 1] TestAgency: Command line: "C:\Program Files (x86)\NUnit.org\nunit-console\nunit-agent.exe" afec5e61-e3eb-472c-a2ff-616b5e30929d tcp://127.0.0.1:62501/TestAgency --trace:Verbose
11:51:58.199 Debug [ 1] TestAgency: Waiting for agent {afec5e61-e3eb-472c-a2ff-616b5e30929d} to register
11:52:28.398 Info [ 1] ServiceManager: Stopping TestFilterService
11:52:28.398 Info [ 1] ServiceManager: Stopping ResultService
11:52:28.398 Info [ 1] ServiceManager: Stopping TestAgency
11:52:28.400 Info [ 1] ServiceManager: Stopping DefaultTestRunnerFactory
11:52:28.400 Info [ 1] ServiceManager: Stopping RuntimeFrameworkService
11:52:28.400 Info [ 1] ServiceManager: Stopping ProjectService
11:52:28.401 Info [ 1] ServiceManager: Stopping RecentFilesService
11:52:28.406 Info [ 1] ServiceManager: Stopping DriverService
11:52:28.406 Info [ 1] ServiceManager: Stopping ExtensionService
11:52:28.406 Info [ 1] ServiceManager: Stopping DomainManager
11:52:28.406 Info [ 1] ServiceManager: Stopping SettingsService
nunit-agent log
11:52:02.641 Debug [ 1] ServiceManager: Added SettingsService
11:52:02.660 Debug [ 1] ServiceManager: Added ExtensionService
11:52:02.660 Debug [ 1] ServiceManager: Added ProjectService
11:52:02.660 Debug [ 1] ServiceManager: Added DomainManager
11:52:02.660 Debug [ 1] ServiceManager: Added InProcessTestRunnerFactory
11:52:02.660 Debug [ 1] ServiceManager: Added DriverService
11:52:02.665 Debug [ 1] ServiceManager: Added SettingsService
11:52:02.665 Debug [ 1] ServiceManager: Added DomainManager
11:52:02.665 Debug [ 1] ServiceManager: Added ExtensionService
11:52:02.665 Debug [ 1] ServiceManager: Added DriverService
11:52:02.665 Debug [ 1] ServiceManager: Added RecentFilesService
11:52:02.665 Debug [ 1] ServiceManager: Added ProjectService
11:52:02.665 Debug [ 1] ServiceManager: Added RuntimeFrameworkService
11:52:02.665 Debug [ 1] ServiceManager: Added DefaultTestRunnerFactory
11:52:02.667 Debug [ 1] ServiceManager: Added TestAgency
11:52:02.667 Debug [ 1] ServiceManager: Added ResultService
11:52:02.667 Debug [ 1] ServiceManager: Added TestFilterService
11:52:02.667 Info [ 1] ServiceManager: Initializing SettingsService
11:52:03.541 Info [ 1] ServiceManager: Initializing ExtensionService
11:52:03.549 Info [ 1] ExtensionService: Scanning nunit.engine assembly for extension points
11:52:03.550 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/NUnitV2Driver, Type=NUnit.Engine.Extensibility.IFrameworkDriver
11:52:57.569 Info [ 1] ExtensionService: Scanning nunit.engine.api assembly for extension points
11:52:57.570 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/IService, Type=NUnit.Engine.IService
11:52:57.571 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/ITestEventListener, Type=NUnit.Engine.ITestEventListener
11:52:57.571 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/IDriverFactory, Type=NUnit.Engine.Extensibility.IDriverFactory
11:52:57.571 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/IProjectLoader, Type=NUnit.Engine.Extensibility.IProjectLoader
11:52:57.571 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/IResultWriter, Type=NUnit.Engine.Extensibility.IResultWriter
11:52:57.577 Info [ 1] ExtensionService: Processing file C:\Program Files (x86)\NUnit.org\nunit-console\nunit.engine.addins
11:53:09.457 Info [ 1] ExtensionService: Scanning C:\Program Files (x86)\NUnit.org\nunit-console\addins\nunit.v2.driver.dll assembly for Extensions
11:53:09.611 Info [ 1] ExtensionService: Found ExtensionAttribute on Type NUnit2FrameworkDriver
11:53:09.625 Info [ 1] ExtensionService: Scanning C:\Program Files (x86)\NUnit.org\nunit-console\addins\nunit-v2-result-writer.dll assembly for Extensions
11:53:09.628 Info [ 1] ExtensionService: Found ExtensionAttribute on Type NUnit2XmlResultWriter
11:53:09.635 Info [ 1] ExtensionService: ExtensionProperty Format = nunit2
11:53:09.635 Info [ 1] ExtensionService: Scanning C:\Program Files (x86)\NUnit.org\nunit-console\addins\nunit-project-loader.dll assembly for Extensions
11:53:09.650 Info [ 1] ExtensionService: Found ExtensionAttribute on Type NUnitProjectLoader
11:53:09.650 Info [ 1] ExtensionService: ExtensionProperty FileExtension = .nunit
11:53:09.650 Info [ 1] ExtensionService: Scanning C:\Program Files (x86)\NUnit.org\nunit-console\addins\vs-project-loader.dll assembly for Extensions
11:53:09.650 Info [ 1] ExtensionService: Found ExtensionAttribute on Type VisualStudioProjectLoader
11:53:09.650 Info [ 1] ExtensionService: ExtensionProperty FileExtension = .sln
11:53:09.650 Info [ 1] ExtensionService: ExtensionProperty FileExtension = .csproj
11:53:09.650 Info [ 1] ExtensionService: ExtensionProperty FileExtension = .vbproj
11:53:09.650 Info [ 1] ExtensionService: ExtensionProperty FileExtension = .vjsproj
11:53:09.650 Info [ 1] ExtensionService: ExtensionProperty FileExtension = .vcproj
11:53:09.650 Info [ 1] ExtensionService: ExtensionProperty FileExtension = .fsproj
...
Something strange is going on in the agent process initialization. First, it adds six services, the ones that are normally used by the agent. Then it adds 11 services, including duplicates of the first six. Those 11 are the ones that are used in the primary copy of the engine, the one that controls everything, and should not be added in the agent. Finally, as you point out, we see close to a one minute delay between scanning the engine assembly and the engine.api assembly.
I'll have to step through this to see what's going on. Was this a run with a single assembly on the command-line? Any special options?
@greg73 I found the reason for the extra services being added and fixed that. Can you try using the consolerunner from this build?
https://ci.appveyor.com/project/CharliePoole/nunit-console/build/3.6.0-ci-03391-issue-117/artifacts
@CharliePoole Thanks for this,
I have tried the new one but I think we may have 2 different issues. I didn't get the extra services being added but I have noticed a long delay for the agent to respond. This may be due to a performance issue on the build server which I will investigate (seems to generally run slow when this happens) but the time does seem excessive. (1 minute from launching agent to anything showing in the log)
internal trace
...
09:57:53.934 Info [ 4] ProcessRunner: Running 1.dll
09:57:53.934 Info [ 6] ProcessRunner: Running 2.dll
09:57:53.934 Info [ 5] ProcessRunner: Running 3.dll
09:57:53.943 Info [ 4] TestAgency: Getting standard agent for use under net-4.5
09:57:53.943 Info [ 6] TestAgency: Getting standard agent for use under net-4.5
09:57:53.943 Info [ 5] TestAgency: Getting standard agent for use under net-4.5
09:57:53.944 Debug [ 4] TestAgency: Using nunit-agent at C:\Program Files (x86)\NUnit.org\nunit-console\nunit-agent.exe
09:57:53.944 Debug [ 5] TestAgency: Using nunit-agent at C:\Program Files (x86)\NUnit.org\nunit-console\nunit-agent.exe
09:57:53.944 Debug [ 6] TestAgency: Using nunit-agent at C:\Program Files (x86)\NUnit.org\nunit-console\nunit-agent.exe
09:57:53.962 Debug [ 6] TestAgency: Launched Agent process 76824 - see nunit-agent_76824.log
09:57:53.962 Debug [ 6] TestAgency: Command line: "C:\Program Files (x86)\NUnit.org\nunit-console\nunit-agent.exe" 0aa4806c-6298-45e1-89c3-c8b246050e09 tcp://127.0.0.1:53676/TestAgency --trace:Verbose
09:57:53.962 Debug [ 6] TestAgency: Waiting for agent {0aa4806c-6298-45e1-89c3-c8b246050e09} to register
09:57:53.963 Debug [ 5] TestAgency: Launched Agent process 2988 - see nunit-agent_2988.log
09:57:53.963 Debug [ 5] TestAgency: Command line: "C:\Program Files (x86)\NUnit.org\nunit-console\nunit-agent.exe" bd3e4dcb-0ca0-481a-9a6e-5c8dc79b8a49 tcp://127.0.0.1:53676/TestAgency --trace:Verbose
09:57:53.963 Debug [ 5] TestAgency: Waiting for agent {bd3e4dcb-0ca0-481a-9a6e-5c8dc79b8a49} to register
09:57:53.965 Debug [ 4] TestAgency: Launched Agent process 6596 - see nunit-agent_6596.log
09:57:53.965 Debug [ 4] TestAgency: Command line: "C:\Program Files (x86)\NUnit.org\nunit-console\nunit-agent.exe" 7e83b584-184f-4eda-a118-1b1e2f24617f tcp://127.0.0.1:53676/TestAgency --trace:Verbose
09:57:53.965 Debug [ 4] TestAgency: Waiting for agent {7e83b584-184f-4eda-a118-1b1e2f24617f} to register
09:58:24.721 Error [ 6] ProcessRunner: Failed to run remote tests Unable to acquire remote process agent
09:58:24.722 Error [ 5] ProcessRunner: Failed to run remote tests Unable to acquire remote process agent
09:58:24.725 Error [ 4] ProcessRunner: Failed to run remote tests Unable to acquire remote process agent
nunit-agent_76824.log
InternalTrace: Initializing at level Debug
09:58:56.486 Debug [ 1] ServiceManager: Added SettingsService
09:58:56.502 Debug [ 1] ServiceManager: Added ExtensionService
09:58:56.503 Debug [ 1] ServiceManager: Added ProjectService
09:58:56.503 Debug [ 1] ServiceManager: Added DomainManager
09:58:56.503 Debug [ 1] ServiceManager: Added InProcessTestRunnerFactory
09:58:56.503 Debug [ 1] ServiceManager: Added DriverService
09:58:56.505 Info [ 1] ServiceManager: Initializing SettingsService
09:59:11.083 Info [ 1] ServiceManager: Initializing ExtensionService
09:59:11.090 Info [ 1] ExtensionService: Scanning nunit.engine assembly for extension points
09:59:11.091 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/NUnitV2Driver, Type=NUnit.Engine.Extensibility.IFrameworkDriver
10:00:23.194 Info [ 1] ExtensionService: Scanning nunit.engine.api assembly for extension points
My hope was that the delay was being caused by there being two extension services active. As far as the internal log goes, nothing seems to be happening for about 50 seconds. I'll see if I can replicate this. Your last run was with three dlls running in separate processes. Are multiple dlls required to reproduce the problem?
Charlie,
Thank you for all your help,
I've discovered the cause of the delay, someone had left the .net Assembly Binding Log Viewer enabled on the server which was creating large numbers of log files when nunit was running. Having turned this off the problems have disappeared.
Maybe an idea to increase the 30 second timeout in case of similar situations where something external causes slow performance?
Should this be in the nunit settings file?
Closing this as not a bug. We can re-open if it turns out there is something more we can do.
I'm hitting this issue too, but only when running NUnit via DotCover on TeamCity, with version 3.6.1 of the NUnit Console Runner. I've tried running with a --trace:Verbose flag but unfortunately via DotCover this doesn't seem to take effect.
Any ideas how I can get sufficient information to enable a repro?
@jamescrowley try running with the --inprocess flag to cause it to run tests in the main runner process. This may expose test initialization errors.
@rprouse thank you - this appears to have given us enough info to go and fix the issues caused by DotCover now. Not sure if this "Unable to acquire remote process agent" is because of these exceptions, or if "--inprocess" has just changed the behaviour - but once I've fixed the underlying errors I will report back.
@rprouse I've now fixed these issues but if I remove "--inprocess" then the "Unable to acquire remote process agent" error returns
I am going to reopen this for now and add the confirm label. What sorts of issues did you need to fix in your tests? Understanding the problems you ran into might give us clues to what is still wrong.
@jamescrowley can you run with the --trace as mentioned above and check the results?
Does this work on your local machine or is it reproducible everywhere?
@rprouse apologies for the delay. they were just path based issues due to NUnit 2 -> 3 upgrade that were hiding behind the issue. Works on my machine, it's running in the non-interactive TC context that seems to be the issue.
When I tried before --trace didn't work via DotCover unless I also passed --inprocess, and then the issue I want the trace on goes away :grin: suggestions welcome!
Sorry, I'm on my phone right now and nearly at my stop on the train, but we added a command line option to load the user profile when launching the agent. Normally we don't because it is expensive, but it might help in your case. Check the console help and let me know. Sorry, I forget the command line switch, but hopefully we wrote the help so it is obvious enough :smile:
@rprouse @CharliePoole is there any further update on this issue. We are seeing this issue when running with ncover. We are seeing this when using ncover run to execute the tests. We have about 40-50 tests that get executed serially
I didn't realize my name was still on this after it was re-opened. I haven't done any more work on it.
@rprouse @CharliePoole me too for this error here's the details :
Windows 10
TeamCity Professional 2017.1.2 (build 46812)
NUnit.ConsoleRunner.3.6.0
.NET Coverage tool: JetBrains dotCover
[15:17:58]Step 5/5: Run Unit Tests (NUnit) (33s)
[15:17:59][Step 5/5] Starting: C:\TeamCity\buildAgent\work\64f706c42d79250c\packages\NUnit.ConsoleRunner.3.6.0\tools\nunit3-console.exe C:\TeamCity\buildAgent\temp\buildTmp\OJb4OMELLV4rzLA0Kxo6M17d32vphWK7.nunit --result=C:\TeamCity\buildAgent\temp\buildTmp\OJb4OMELLV4rzLA0Kxo6M17d32vphWK7.nunit.xml --noheader
[15:17:59][Step 5/5] in directory: C:\TeamCity\buildAgent\work\64f706c42d79250c\MyProject.Tests\bin\Debug
[15:18:00][Step 5/5] Runtime Environment
[15:18:00][Step 5/5] OS Version: Microsoft Windows NT 10.0.15063.0
[15:18:00][Step 5/5] CLR Version: 4.0.30319.42000
[15:18:00][Step 5/5]
[15:18:00][Step 5/5] Test Files
[15:18:00][Step 5/5] C:\TeamCity\buildAgent\temp\buildTmp\OJb4OMELLV4rzLA0Kxo6M17d32vphWK7.nunit
[15:18:00][Step 5/5]
[15:18:30][Step 5/5]
[15:18:30][Step 5/5] Errors, Failures and Warnings
[15:18:30][Step 5/5]
[15:18:30][Step 5/5] 1) Error : C:\TeamCity\buildAgent\temp\buildTmp\OJb4OMELLV4rzLA0Kxo6M17d32vphWK7.nunit
[15:18:30][Step 5/5] Unable to acquire remote process agent
[15:18:30][Step 5/5] at NUnit.Engine.Runners.ProcessRunner.CreateAgentAndRunner()
[15:18:30][Step 5/5] at NUnit.Engine.Runners.ProcessRunner.RunTests(ITestEventListener listener, TestFilter filter)
removing dotCover does not help
I just had the same issue running a 3.7.0 testcase with the 3.6 nunit console on teamcity. using 3.7.0 on teamcity solved it.
The 3.7.0 console runner solved it?
yes, the visual studio project used nunit 3.7.0; my teamcity installed 3.6.0 in a pre-build-step. its because the teamcity nunit build step tutorial demonstrates it with 3.6.0.
Good to know, thanks!
Sigh. Alas I am currently seeing the same problem with the 3.7.0 console runner. :-(
From the log file:
NUnit Console Runner 3.7.0
Copyright (c) 2017 Charlie Poole, Rob Prouse
Runtime Environment
OS Version: Microsoft Windows NT 6.1.7601 Service Pack 1
CLR Version: 4.0.30319.42000
...
1) Error : C:\SourceCode\Product\Build\UnitTests\x86\Debug\Autopoll\Autopoll.Tests.dll
Unable to acquire remote process agent
at NUnit.Engine.Runners.ProcessRunner.CreateAgentAndRunner()
at NUnit.Engine.Runners.ProcessRunner.RunTests(ITestEventListener listener, TestFilter filter)
2) Error : C:\SourceCode\Product\Build\UnitTests\x86\Debug\BinaryData\BinaryData.Tests.dll
Unable to acquire remote process agent
at NUnit.Engine.Runners.ProcessRunner.CreateAgentAndRunner()
at NUnit.Engine.Runners.ProcessRunner.RunTests(ITestEventListener listener, TestFilter filter)
I note that a lot of the nunit-agent-nnnn.log files look like this:
InternalTrace: Initializing at level Debug
15:47:53.398 Debug [ 1] ServiceManager: Added SettingsService
15:47:53.492 Debug [ 1] ServiceManager: Added ExtensionService
15:47:53.493 Debug [ 1] ServiceManager: Added ProjectService
15:47:53.516 Debug [ 1] ServiceManager: Added DomainManager
15:47:53.516 Debug [ 1] ServiceManager: Added InProcessTestRunnerFactory
15:47:53.516 Debug [ 1] ServiceManager: Added DriverService
15:47:53.520 Info [ 1] ServiceManager: Initializing SettingsService
15:47:54.398 Info [ 1] ServiceManager: Initializing ExtensionService
15:47:54.400 Info [ 1] ExtensionService: Scanning nunit.engine assembly for extension points
15:47:54.412 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/NUnitV2Driver, Type=NUnit.Engine.Extensibility.IFrameworkDriver
15:47:56.418 Info [ 1] ExtensionService: Scanning nunit.engine.api assembly for extension points
15:47:56.420 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/IService, Type=NUnit.Engine.IService
15:47:56.421 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/ITestEventListener, Type=NUnit.Engine.ITestEventListener
15:47:56.421 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/IDriverFactory, Type=NUnit.Engine.Extensibility.IDriverFactory
15:47:56.421 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/IProjectLoader, Type=NUnit.Engine.Extensibility.IProjectLoader
15:47:56.421 Info [ 1] ExtensionService: Found Path=/NUnit/Engine/TypeExtensions/IResultWriter, Type=NUnit.Engine.Extensibility.IResultWriter
15:47:56.444 Info [ 1] ExtensionService: Processing file C:\SourceCode\Viper_Default_git\tools\NUnit.ConsoleRunner\tools\nunit.nuget.addins
15:47:56.535 Info [ 1] ServiceManager: Initializing ProjectService
15:47:56.537 Debug [ 1] ServiceManager: Request for service ExtensionService satisfied by ExtensionService
15:47:56.539 Info [ 1] ServiceManager: Initializing DomainManager
15:47:56.539 Info [ 1] ServiceManager: Initializing InProcessTestRunnerFactory
15:47:56.539 Info [ 1] ServiceManager: Initializing DriverService
15:47:56.540 Debug [ 1] ServiceManager: Request for service ExtensionService satisfied by ExtensionService
15:47:56.575 Info [ 1] RemoteTestAgent: Agent starting
15:47:57.035 Info [ 1] RemoteTestAgent: Connecting to TestAgency at tcp://127.0.0.1:5653/TestAgency
15:47:57.590 Debug [ 1] RemoteTestAgent: Registered with TestAgency
Only some of them show a subsequent ServiceManager interaction to load a test assembly.
Agents were launched within a very similar time window. I didn't see any obvious time-based relationship between agents that successfully processed a test assembly and those that didn't.
I'm afraid this will be another elusive and arcane remoting time sink. I'm looking for https://github.com/nunit/nunit-console/issues/266 to be a near-term answer.
You may be right. For anyone coming along afterwards, I did find what appears to be a viable work-around. The maximum test agents had been left at the default (unlimited) value. Adjusting that value down to something smaller (I chose 3, but based on the log file my machine may be able to support as many as 8) eliminated the error while still allowing all the tests to run. It just didn't run as many of the tests in parallel.
I did run in the same problems, but could fix them with @RichardJFoster tip by adding the parameters
--inprocess --agents=2
@muellnes Those options are contradictory and don't use any agents at all. The --inprocess option means "run in process, rather than creating agents" and the --agents option is ignored.
I have the same problem when calling NUnit.Console 3.8.0 via OpenCover 4.6.519. Limiting the agents to two, solved the problem for me.
This looks like it could be the same cause as https://github.com/nunit/nunit-console/issues/436 - which we will hopefully have a fix in for soon.
Most helpful comment
@muellnes Those options are contradictory and don't use any agents at all. The --inprocess option means "run in process, rather than creating agents" and the --agents option is ignored.