Rider 2018.2 takes 14 minutes to start running tests with x64 architecture (NUnit)
The problem started happening with a single test project (other test projects seem to be fine).
Whenever I kick off a test session (doesn't matter if it's a single test or 150) it will take about 14 minutes for ReSharper test runner to start running the tests. I am entirely sure this is related to ReSharper test runner since I'm having the same problem running tests with ReSharper in Visual Studio. Also what is interesting I have tried running the tests with x86 architecture and it seems to run just fine (however all of my tests are failing due to architecture incompatibility).
So far I've tried: full clean, instantiating another copy of git repo and doing a clean build + test run there, reinstalling both Rider and ReSharper (a couple of times), wiping the cache (File -> Invalidate Caches / Restart). Nothing seems to help...
As you can see from the log, the process just starts and doesn't do anything for about 14 minutes:
10:46:13.238 |I| DiscoveryStage completed
10:46:13.239 |I| BuildPipelineStage started
10:46:13.240 |I| BuildPipelineStage completed
10:46:13.240 |I| ApplyRulesStage started
10:46:13.246 |I| Got 133 elements (0 explicit) to run
10:46:13.247 |V| Marking 133 elements as Pending
10:46:13.268 |V| Marking elements as Pending completed
10:46:13.268 |V| Distributing 133 elements into runs
10:46:13.352 |V| Distributing elements completed
10:46:13.352 |I| Created 1 unit-test runs
10:46:13.353 |I| ApplyRulesStage completed
10:46:13.353 |I| RunTestsStage started
10:46:13.355 |I| Running up to 1 unit-test runs in parallel
10:46:13.356 |I| Run: 4c05976b-c26d-4cd9-b6ac-bf3693798c8e - Starting
10:46:13.356 |V| Provider: NUnit 3x
Target Framework: .NETFramework,Version=v4.7
Strategy: NUnitOutOfProcessUnitTestRunStrategy
Runtime Enviroment: TaskRunnerRuntimeEnvironment
TargetPlatform: X64
PlatformVersion: v4_5
IsUnmanaged: False
PlatformMonoPreference: PreferClr
10:46:13.357 |T| Run: 4c05976b-c26d-4cd9-b6ac-bf3693798c8e >> RunHostController.PrepareForRun
10:46:13.357 |T| Run: 4c05976b-c26d-4cd9-b6ac-bf3693798c8e << RunHostController.PrepareForRun
10:46:13.360 |I| [ProcessStartInfoPatchResult]
Original request: FrameworkRequest (UseInternal: False, UseMono: False, MonoDebugMode: True, MonoPlatform: PreferX64)
Success: True
ErrorMessage: <Empty>
Original StartInfo: FileName = 'C:\Program Files\JetBrains\JetBrains Rider 2018.2.1 Reinstalled\lib\ReSharperHost\JetBrains.ReSharper.TaskRunner.CLR45.x64.exe', Arguments = '"127.0.0.1" "62605" "4c05976b-c26d-4cd9-b6ac-bf3693798c8e"', WorkDir = 'C:\Program Files\JetBrains\JetBrains Rider 2018.2.1 Reinstalled\lib\ReSharperHost'
Patched StartInfo: FileName = 'C:\Program Files\JetBrains\JetBrains Rider 2018.2.1 Reinstalled\lib\ReSharperHost\JetBrains.ReSharper.TaskRunner.CLR45.x64.exe', Arguments = '"127.0.0.1" "62605" "4c05976b-c26d-4cd9-b6ac-bf3693798c8e"', WorkDir = 'C:\Program Files\JetBrains\JetBrains Rider 2018.2.1 Reinstalled\lib\ReSharperHost'
10:46:13.361 |I| Starting process: C:\Program Files\JetBrains\JetBrains Rider 2018.2.1 Reinstalled\lib\ReSharperHost\JetBrains.ReSharper.TaskRunner.CLR45.x64.exe "127.0.0.1" "62605" "4c05976b-c26d-4cd9-b6ac-bf3693798c8e"
10:46:13.370 |I| Started process with pid 8408
11:00:59.761 |V| Run: 4c05976b-c26d-4cd9-b6ac-bf3693798c8e - Discovery started
11:00:59.790 |V| Marking 46 elements as Pending
11:00:59.792 |V| Marking elements as Pending completed
11:00:59.792 |V| Distributing 46 elements into runs
11:00:59.799 |V| Distributing elements completed
11:00:59.799 |V| Run: 4c05976b-c26d-4cd9-b6ac-bf3693798c8e - Discovery finished
11:01:09.205 |I| Process C:\Program Files\JetBrains\JetBrains Rider 2018.2.1 Reinstalled\lib\ReSharperHost\JetBrains.ReSharper.TaskRunner.CLR45.x64.exe:8408 has exited with code (0)
Output stream:
Error stream:
11:01:09.207 |T| Run: 4c05976b-c26d-4cd9-b6ac-bf3693798c8e >> RunHostController.CleanupAfterRun
11:01:09.207 |T| Run: 4c05976b-c26d-4cd9-b6ac-bf3693798c8e << RunHostController.CleanupAfterRun
11:01:09.207 |I| Run: 4c05976b-c26d-4cd9-b6ac-bf3693798c8e - Finished
11:01:09.207 |I| RunTestsStage completed
11:01:09.208 |I| FinishLaunchStage started
11:01:09.208 |I| Finishing run
11:01:09.210 |I| Run is finished
11:01:09.210 |I| FinishLaunchStage completed
11:01:09.210 |T| Launch: 04847655-5b4d-4eed-a4ab-ed287d5a922d >> RunHostController.BeforeLaunchFinished
11:01:09.210 |T| Launch: 04847655-5b4d-4eed-a4ab-ed287d5a922d << RunHostController.BeforeLaunchFinished
Please sign in to leave a comment.
Hi!
Could you please
Kind regards,
Sofya
Thanks for the reply, Sofia,
I've uploaded the memory profile via HTTP (https://uploads.services.jetbrains.com/) the file is named 7a8943c8-0ed9-4ce7-ae24-891b8a414f40.zip
Thanks!
We will investigate it ASAP.
Sofia
Hi!
We need some more information.
Could you please send us test runner specific logs? How to do that is described here.
Sofia.
Hello, I'm terribly sorry for not replying earlier. I have tracked down the issue. I got mislead by the logs thinking that it was ReSharper task runner while the culprit was elsewhere. The real problem was NUnit and Autofixture (which I use to autogenerate data for tests). I am using [TestCaseData] attributes that use AutoFixture to autogenerate a set of objects which can have similar related objects. I have configured AutoFixture to limit the depth to which it goes to generate said objects to prevent unchecked recursion depth from happening. However after a certain nuget package update generated object count jumped to thousands of objects for every test that used said TestCaseData attribute and used those objects. That alone wouldn't have caused me to suspect the task runner, however even running a single test within the unit test project causes NUnit to preload all test case data for ALL tests and since I've done full ReSharper and Rider update on this system the same day and looking at the logs it looked like ReSharper task runner might be hanging for some reason.
Again...sorry, hopefully this might save someone else a lot of time in the future.