Welcome Guest! To enable all features please Login or Register.

Notification

Icon
Error

2 Pages12>
Analysis of Visual Studio 2017 solution order of magnitude slower
donners77
#1 Posted : Tuesday, March 13, 2018 5:56:18 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
Hi.

I converted a solution from Visual Studio 2015 to Visual Studio 2017. In the process, I consolidated a number of projects together and converted the C# project files over to the new .csproj file format (the F# projects are still in the old .fsproj file format).

Before, there were 163 projects and the analysis phase after ncrunch had loaded all the projects took 10 to 20 seconds before it started running the tests.

Now, there are 147 projects and the analysis phase is taking approximately 9 minutes.

Kind regards,
Craig.
Remco
#2 Posted : Tuesday, March 13, 2018 9:25:46 PM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
Hi Craig,

Thanks for sharing this issue. The first thing I'd check is to make sure you're running the latest version of NCrunch. v3.12 introduced some critical performance improvements when dealing with analysis steps on large projects - if you are running an older version than this, I'd recommend upgrading as soon as possible.

Assuming you are using the latest version of NCrunch, we'll need to take a look at some performance data from the engine. Enable the track engine performance setting, then try letting the engine do a full build and run cycle. Find one of the tests related to the project with the long analysis time, then select it in the Tests Window. You should see a tab available for 'Execution Steps'. Which execution steps took a long time? Does the report highlight anything of interest?
1 user thanked Remco for this useful post.
donners77 on 3/13/2018(UTC)
donners77
#3 Posted : Tuesday, March 13, 2018 11:22:00 PM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
Hi Remco,

I'm running ncrunch version 3.14.0.1

I've enabled the track engine performance setting and below is an example of what I get (I'm not sure what I am supposed to be looking for)...

Step Duration Started At Finished At
All steps required for the execution of DateJustRangeBehaviour.* 00:12:35.1081092 3/13/2018 10:51:12 PM 3/13/2018 11:03:47 PM
Filter tests to identify execution targets 00:00:00.0065421 3/13/2018 10:51:12 PM 3/13/2018 10:51:12 PM
Enqueue tests for execution with normal priority 00:00:00.4324866 3/13/2018 10:51:12 PM 3/13/2018 10:51:12 PM
Waiting in processing queue 00:00:00.7075223 3/13/2018 10:51:12 PM 3/13/2018 10:51:13 PM
Dependency 'Build TestHelperFs on (local)' 00:12:03.8791041 3/13/2018 10:51:13 PM 3/13/2018 11:03:17 PM
Dependency 'Build LibBase on (local)' 00:11:59.5390420 3/13/2018 10:51:17 PM 3/13/2018 11:03:17 PM
Dependency 'Build LibHash on (local)' 00:00:00.6260647 3/13/2018 10:51:17 PM 3/13/2018 10:51:18 PM
Dependency 'Analyse TestHelperFs on (local)' 00:00:00.9560269 3/13/2018 11:03:17 PM 3/13/2018 11:03:18 PM
Dependency 'Build LibDates on (local)' 00:00:01.8522115 3/13/2018 11:03:17 PM 3/13/2018 11:03:19 PM
Dependency 'Build LibType on (local)' 00:00:01.9142188 3/13/2018 11:03:17 PM 3/13/2018 11:03:19 PM
Dependency 'Build LibCache on (local)' 00:00:01.6067514 3/13/2018 11:03:18 PM 3/13/2018 11:03:19 PM
Dependency 'Build LibStrings on (local)' 00:00:01.4749872 3/13/2018 11:03:18 PM 3/13/2018 11:03:20 PM
Dependency 'Build LibValueObj on (local)' 00:00:01.4902487 3/13/2018 11:03:18 PM 3/13/2018 11:03:20 PM
Dependency 'Build LibExpression on (local)' 00:00:01.2623709 3/13/2018 11:03:19 PM 3/13/2018 11:03:21 PM
Dependency 'Build LibSinkConsole on (local)' 00:00:01.1367394 3/13/2018 11:03:20 PM 3/13/2018 11:03:21 PM
Dependency 'Build LibId on (local)' 00:00:00.9907685 3/13/2018 11:03:20 PM 3/13/2018 11:03:21 PM
Dependency 'Build LibRefen on (local)' 00:00:01.6773918 3/13/2018 11:03:20 PM 3/13/2018 11:03:22 PM
Dependency 'Build LibPredicates on (local)' 00:00:01.0190465 3/13/2018 11:03:21 PM 3/13/2018 11:03:22 PM
Dependency 'Build LibRecords on (local)' 00:00:01.4299998 3/13/2018 11:03:22 PM 3/13/2018 11:03:23 PM
Dependency 'Build LibLog on (local)' 00:00:01.0847453 3/13/2018 11:03:22 PM 3/13/2018 11:03:23 PM
Dependency 'Build LibActives on (local)' 00:00:02.5988765 3/13/2018 11:03:23 PM 3/13/2018 11:03:26 PM
Dependency 'Build LibLogConsole on (local)' 00:00:02.0600048 3/13/2018 11:03:24 PM 3/13/2018 11:03:26 PM
Dependency 'Build LibLogSeri on (local)' 00:00:01.9497312 3/13/2018 11:03:24 PM 3/13/2018 11:03:26 PM
Dependency 'Build LibLogWConfig on (local)' 00:00:01.1585627 3/13/2018 11:03:26 PM 3/13/2018 11:03:27 PM
Waiting in processing queue 00:00:00.5865753 3/13/2018 11:03:27 PM 3/13/2018 11:03:27 PM
Dependency 'Build LibCheckDigits on (local)' 00:00:00.6734304 3/13/2018 11:03:27 PM 3/13/2018 11:03:28 PM
Dependency 'Build TestFastLibBase on (local)' 00:00:11.6696391 3/13/2018 11:03:28 PM 3/13/2018 11:03:40 PM
Dependency 'Analyse TestFastLibBase on (local)' 00:00:01.9835835 3/13/2018 11:03:40 PM 3/13/2018 11:03:42 PM
Waiting in processing queue 00:00:00.0949969 3/13/2018 11:03:42 PM 3/13/2018 11:03:42 PM
Prepare primary task for processing 'Run tests from TestFastLibBase' 00:00:00.0014805 3/13/2018 11:03:42 PM 3/13/2018 11:03:42 PM
Process task 'Run tests from TestFastLibBase on (local)' 00:00:04.6807483 3/13/2018 11:03:42 PM 3/13/2018 11:03:47 PM
Complete processing of task 'Run tests from TestFastLibBase on (local)' 00:00:00.0024987 3/13/2018 11:03:47 PM 3/13/2018 11:03:47 PM
Register result data for test 'DateJustRangeBehaviour' with engine 00:00:00 3/13/2018 11:03:47 PM 3/13/2018 11:03:47 PM
Merge test code coverage data 00:00:00.1549763 3/13/2018 11:03:47 PM 3/13/2018 11:03:47 PM
Remco
#4 Posted : Tuesday, March 13, 2018 11:25:42 PM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
Dependency 'Build TestHelperFs on (local)' 00:12:03.8791041 3/13/2018 10:51:13 PM 3/13/2018 11:03:17 PM
Dependency 'Build LibBase on (local)' 00:11:59.5390420 3/13/2018 10:51:17 PM 3/13/2018 11:03:17 PM

These two dependencies are taking about 12 minutes to build/analyse.

You should be able to drill down into the tasks to see what's taking the time.

If you like, you can export the contents of the tree and paste it in here or submit it via the contact form.
1 user thanked Remco for this useful post.
donners77 on 3/14/2018(UTC)
donners77
#5 Posted : Wednesday, March 14, 2018 12:00:35 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
Hi Remco,

It looks like "(not specified)" is taking the time...

Step Duration Started At Finished At
All steps required for the execution of DateJustRangeBehaviour.* 00:13:00.4570961 3/13/2018 11:42:00 PM 3/13/2018 11:55:00 PM
Filter tests to identify execution targets 00:00:00.0064992 3/13/2018 11:42:00 PM 3/13/2018 11:42:00 PM
Enqueue tests for execution with normal priority 00:00:00.3314505 3/13/2018 11:42:00 PM 3/13/2018 11:42:00 PM
Waiting in processing queue 00:00:02.2748933 3/13/2018 11:42:00 PM 3/13/2018 11:42:02 PM
Dependency 'Build TestHelperFs on (local)' 00:12:22.0681074 3/13/2018 11:42:02 PM 3/13/2018 11:54:25 PM
Prepare task for processing 'Build TestHelperFs on (local)' 00:00:00 3/13/2018 11:42:02 PM 3/13/2018 11:42:02 PM
Process task 'Build TestHelperFs on (local)' 00:00:07.8451734 3/13/2018 11:42:02 PM 3/13/2018 11:42:10 PM
Acquire workspace for project 00:00:00.1864875 3/13/2018 11:42:02 PM 3/13/2018 11:42:03 PM
Map referenced assemblies in preparation for build 00:00:00.0234987 3/13/2018 11:42:03 PM 3/13/2018 11:42:03 PM
Index instrumentation directives 00:00:00 3/13/2018 11:42:03 PM 3/13/2018 11:42:03 PM
Acquire host process for build task 00:00:00.0040005 3/13/2018 11:42:03 PM 3/13/2018 11:42:03 PM
(not specified) 00:00:00.3164994 3/13/2018 11:42:03 PM 3/13/2018 11:42:03 PM
Send instructions to host process over IPC 00:00:00.0365010 3/13/2018 11:42:03 PM 3/13/2018 11:42:03 PM
Prepare MSBuild parameters 00:00:00.6381188 3/13/2018 11:42:03 PM 3/13/2018 11:42:04 PM
(not specified) 00:00:00.0421039 3/13/2018 11:42:04 PM 3/13/2018 11:42:04 PM
Invoke MSBuild 00:00:05.4457317 3/13/2018 11:42:04 PM 3/13/2018 11:42:09 PM
Perform post-build processing on primary output assembly 00:00:01.0828689 3/13/2018 11:42:09 PM 3/13/2018 11:42:10 PM
Return results to engine over IPC 00:00:00.0084988 3/13/2018 11:42:10 PM 3/13/2018 11:42:10 PM
Align assembly references using build output 00:00:00.0024976 3/13/2018 11:42:10 PM 3/13/2018 11:42:10 PM
Prepare .config file for selected test frameworks 00:00:00 3/13/2018 11:42:10 PM 3/13/2018 11:42:10 PM
(not specified) 00:12:14.2214317 3/13/2018 11:42:10 PM 3/13/2018 11:54:25 PM
Complete processing of task 'Build TestHelperFs on (local)' 00:00:00 3/13/2018 11:54:25 PM 3/13/2018 11:54:25 PM
Merge code-line data from build 00:00:00 3/13/2018 11:54:25 PM 3/13/2018 11:54:25 PM
Dependency 'Build LibBase on (local)' 00:12:16.9009719 3/13/2018 11:42:08 PM 3/13/2018 11:54:25 PM
Prepare task for processing 'Build LibBase on (local)' 00:00:00 3/13/2018 11:42:08 PM 3/13/2018 11:42:08 PM
Process task 'Build LibBase on (local)' 00:00:02.9828103 3/13/2018 11:42:08 PM 3/13/2018 11:42:11 PM
Acquire workspace for project 00:00:01.2570865 3/13/2018 11:42:08 PM 3/13/2018 11:42:09 PM
Map referenced assemblies in preparation for build 00:00:00 3/13/2018 11:42:09 PM 3/13/2018 11:42:09 PM
Index instrumentation directives 00:00:00.0014992 3/13/2018 11:42:09 PM 3/13/2018 11:42:09 PM
Acquire host process for build task 00:00:00.0069720 3/13/2018 11:42:09 PM 3/13/2018 11:42:09 PM
Send instructions to host process over IPC 00:00:00.0064986 3/13/2018 11:42:09 PM 3/13/2018 11:42:09 PM
Prepare MSBuild parameters 00:00:00.2735317 3/13/2018 11:42:09 PM 3/13/2018 11:42:09 PM
Invoke MSBuild 00:00:00.8090695 3/13/2018 11:42:09 PM 3/13/2018 11:42:10 PM
Perform post-build processing on primary output assembly 00:00:00.5323863 3/13/2018 11:42:10 PM 3/13/2018 11:42:11 PM
Return results to engine over IPC 00:00:00.0536808 3/13/2018 11:42:11 PM 3/13/2018 11:42:11 PM
Align assembly references using build output 00:00:00.0008929 3/13/2018 11:42:11 PM 3/13/2018 11:42:11 PM
(not specified) 00:12:13.9166614 3/13/2018 11:42:11 PM 3/13/2018 11:54:25 PM
Complete processing of task 'Build LibBase on (local)' 00:00:00 3/13/2018 11:54:25 PM 3/13/2018 11:54:25 PM
Merge code-line data from build 00:00:00.0004996 3/13/2018 11:54:25 PM 3/13/2018 11:54:25 PM
Dependency 'Build LibHash on (local)' 00:12:16.1414954 3/13/2018 11:42:08 PM 3/13/2018 11:54:24 PM
Remco
#6 Posted : Wednesday, March 14, 2018 12:55:55 AM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
This is interesting. The problem here doesn't look like it's in the actual build task itself, it's in the engine. The thread being used by the engine is being tied up by something for a full 12 minutes. Because the completion of the task is reliant on the engine to process it, it gets held up.

We need to get a detailed log of what the engine is doing when it locks up like this. Unfortunately because of the nature of the problem, the NCrunch bug reporter won't really work for this, so it'll need to be a manual extract.

To get an extract of the log, you'll need to do the following:
1. Turn on the 'Log to output window' configuration setting
2. Set the 'Log verbosity' to 'Detailed'
3. Everything will run very slowly
4. Open Debug->Windows->Output->NCrunch Output Window
5. Start things up so that NCrunch falls into the 'locked' state

Whatever is showing in the log at this stage is of importance, as it will tell us what the engine is doing. I'm willing to bet that whatever has the engine this busy is probably logging things like crazy, so it may be quite tough to get a manageable extract from the log. If you can copy/paste the contents of this into a file, ZIP it up and submit it through the contact form I should be able to analyse it from here.
donners77
#7 Posted : Wednesday, March 14, 2018 2:14:07 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
Hi. I'm running with verbose debugging now.
After a flurry of output, it is just sitting for a long time without any new debug lines appearing on the screen.
The last few were...

ENGINE - [02:08:08.6806-LocalBuildTask-16] Build was successful for C:\Users\xxxxxxxx\AppData\Local\NCrunch\9876\14\CoreComponents\bin\Debug\net47\LibBase.dll
ENGINE - [02:08:08.6806-LocalBuildTask-16] Task processing complete for [LocalBuildTask: [SnapshotComponent: LibBase, 121, 12233283], BeingProcessed, (local), b37457f4-918b-4d30-950c-fb4e28650399], processing time: 00:00:00
ENGINE - [02:08:08.6806-LocalBuildTask-16] Publishing Event: [ :[LocalBuildTask: [SnapshotComponent: LibBase, 121, 12233283], BeingProcessed, (local), b37457f4-918b-4d30-950c-fb4e28650399]]
ENGINE - [02:08:08.6806-LocalBuildTask-16] Event [ :[LocalBuildTask: [SnapshotComponent: LibBase, 121, 12233283], BeingProcessed, (local), b37457f4-918b-4d30-950c-fb4e28650399]] is being published on thread CoreThread to subscriber: ProcessingQueue.
ENGINE - [02:08:08.6806-LocalBuildTask-16] Event [ :[LocalBuildTask: [SnapshotComponent: LibBase, 121, 12233283], BeingProcessed, (local), b37457f4-918b-4d30-950c-fb4e28650399]] is being published on thread UIThread to subscriber: SharedEventPump.
[02:08:18.9103-UI-1] No retained maps to be applied to new code coverage for:
[02:08:18.9252-UI-1] Publishing Event: [:nCrunch.VSAddIn.UI.MenuOptions.MainMenu.StopMenuOption+.]
[02:08:18.9262-UI-1] Event [:nCrunch.VSAddIn.UI.MenuOptions.MainMenu.StopMenuOption+.] is being published on thread UIThread to subscriber: .
[02:08:18.9262-UI-1] Event [:nCrunch.VSAddIn.UI.MenuOptions.MainMenu.StopMenuOption+.] is being published on thread CoreThread to subscriber: SharedEventPump.
[02:08:18.9262-Core-462] Event [:nCrunch.VSAddIn.UI.MenuOptions.MainMenu.StopMenuOption+.] is being processed on Core thread with subscriber: SharedEventPump.
ENGINE - [02:10:06.878-?-49] Publishing Event: [:nCrunch.Client.Model.LineMapDeallocator.]
ENGINE - [02:10:06.879-?-49] Event [:nCrunch.Client.Model.LineMapDeallocator.] is being published on thread CoreThread to subscriber: .
ENGINE - [02:10:06.879-?-49] Event [:nCrunch.Client.Model.LineMapDeallocator.] is being published on thread UIThread to subscriber: SharedEventPump.
Remco
#8 Posted : Wednesday, March 14, 2018 2:26:03 AM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
When it reached the point where no lines were being written, were the tasks still sitting in progress in the Processing Queue Window?
donners77
#9 Posted : Wednesday, March 14, 2018 2:29:21 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
Yes and Task Manager showed the Engine thread sitting around 15% of CPU for about 10 minutes, after which a mass of new lines was generated.
donners77
#10 Posted : Wednesday, March 14, 2018 2:32:34 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
I've uploaded the start of the debug lines that came after the 10 minute pause via your contact form.
Remco
#11 Posted : Wednesday, March 14, 2018 2:40:14 AM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
donners77;11910 wrote:
I've uploaded the start of the debug lines that came after the 10 minute pause via your contact form.


Thanks, I hope it gets through .. the contact form does have a size limit :(

The most critical part of the log is the 10,000 odd lines after the extract you posted here. This would be the log from where the stall happened.

My guess at the moment is that this is a project synchronisation problem. Perhaps something in the load or build of your projects is causing VS to refresh the projects from disk, which then feeds back into NCrunch so that NCrunch needs to reload again, causing the loop to happen again. There were occurrences of this while stabilising NCrunch under VS2017. Right now though, I can't really confirm this without the logs. Nor is it clear to me why this is affecting you but not other users. Do you have any build customisations or are you making use of any third party software that might involve custom build steps or build integration?
donners77
#12 Posted : Wednesday, March 14, 2018 2:46:33 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
I uploaded the next 69,000 lines which wasn't very big at all when zipped. Let me know if you need more.

I am not aware of any build customisations or any third party software that might involve custom build steps or build integration.

I seeing this behaviour on 2 different computers - a desktop and a virtual machine in Azure.
Remco
#13 Posted : Wednesday, March 14, 2018 3:01:24 AM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
Thanks, I have the log. At the moment this looks like the engine is stuck trying to sift through the processing queue to pick up new work.

Roughly how many tasks do you usually have in the processing queue, and how many tests are there in your solution? Does clearing your NCrunch cache file have any effect? (Just delete the contents of the _NCrunch_* directory while the engine is offline).
donners77
#14 Posted : Wednesday, March 14, 2018 3:30:44 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
Do you mean the number of processing tasks that can run at the same time? There are 4 CPUs allocated to ncrunch and the Max number of processing threads in 8.

I deleted the contents of the c:\ncrunch\ directory where I have configured the NCrunch storage cache path to. Is that what you meant? The long delay still occurs.

There are 4,436 tests.
Remco
#15 Posted : Wednesday, March 14, 2018 3:44:22 AM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
donners77;11914 wrote:

I deleted the contents of the c:\ncrunch\ directory where I have configured the NCrunch storage cache path to. Is that what you meant? The long delay still occurs.

There are approximately 5,000 unit tests (I can't see the exact number at the moment as it doesn't show till after the long delay).


Thanks for this extra information. I think that there are a couple of things that are contributing to this problem.

The first is that it's quite possible the engine is working over capacity given the CPU resources that have been assigned to it. Check to see whether the 'Max number of processing threads' you have configured is an approximate match for the number of CPU cores that are assigned to NCrunch. If the max processing threads are too high, it's possible for the engine to get sidelined by the user processing it's doing. Even when heavily overloaded, the engine will still run, it'll just run slower. The act of pulling work from the processing queue is a known bottleneck so it's probably just the most obvious place for things to get hung up.

I suspect the other contributor is the 'first time run' problem. Probably when you shifted up to VS2017, all the data NCrunch held on your test execution times would have been thrown away (we used to do this when updating the software, though in the most recent versions we have a more reliable way to retain this data). This would mean that the first pipeline constructed by NCrunch would be really inefficient, with probably just 1-10 tests per execution task. Once the engine has run through all your tests and has up-to-date cache data, the processing queue will be much smaller and the engine should work much more efficiently. So I guess the thing to try here would be to let the engine spin for a while until it's run all your tests through to completion, then disable NCrunch in an orderly fashion. I would hope that the next time you spin the engine up, the hang up will be much smaller or hopefully non existent.

Edit: I should probably add that with NCrunch v3.13, we added a new feature that allows you to track the 'core load' of the NCrunch engine. This feature is pretty new so we're still feeling it out, but by hovering the mouse over the corner status indicator, you'll see a bar that tells you the 'Core Load' of the NCrunch engine. When this load reaches 100%, it means that the engine's core thread is overloaded. I hope this might help to give you a better visual indicator of the hang-ups without needing to wait on an unresponsive engine.
donners77
#16 Posted : Wednesday, March 14, 2018 9:34:00 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
Hi Remco,

There are 4 CPU's assigned to ncrunch and 4 to Visual Studio (total 8). The max number of ncrunch processing threads is set to 8. These settings were the same when I was using Visual Studio 2015 and there wasn't the long delay problem. Should I change any of these settings?

I suspect that the engine is not getting sidelined during the long delay by user processing on the queue as there doesn't seem to be anything on the queue during that time.

I also suspect that this is not the 'first time run' problem, as I have run ncrunch many times with the visual studio 2017 solution, including disabling ncrunch is an orderly fashion and then restarting it and it makes no difference, the long delay still occurs.

I have uploaded the following screenshots via contact us so you can see a bit more of what is happening (or not happening) as the case may be:
- Engine delay: summary view during the delay
- Engine delay: process queue during the delay
- Engine delay: task manager during the delay
- Engine delay:summary after the delay (when tests are now running)
- Engine delay: various after the delay (when tests are now running)
Remco
#17 Posted : Wednesday, March 14, 2018 11:02:30 PM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
Thanks Craig. I think I now have enough information to attempt to create a test scenario that can reproduce this problem. I'll let you know how it goes!

Regarding the CPU/Thread settings, my rule of thumb is to have the same number of threads assigned to NCrunch as you have CPU cores assigned to it. So in this case, that would be a max number of 4 processing threads. There is no hard rule for this as it depends very much on the nature of your tests. The only way to find the right setting is through experimentation.
1 user thanked Remco for this useful post.
donners77 on 3/14/2018(UTC)
Remco
#18 Posted : Friday, March 16, 2018 2:48:31 AM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
1 user thanked Remco for this useful post.
donners77 on 3/16/2018(UTC)
donners77
#19 Posted : Saturday, March 17, 2018 12:00:03 AM(UTC)
Rank: Member

Groups: Registered
Joined: 3/13/2018(UTC)
Posts: 18
Location: Australia

Thanks: 4 times
Hi Remco,

Thank you. I've given it a go and I can see an improvement, but not relating to the major delay issue I have been experiencing.

The improvement I see is that I'm no longer getting timeouts once tests eventually do start to run.

However, the core engine host is still unresponsive for around 10 minutes after the initial solution build.

I have noticed that once the core host engine has resumed working and tests start running, the unresponsiveness will usually reoccur for another 10 minutes if I make a change to the code within the LibBase C# project. Perhaps there is something post build of that particular project that is causing the ncrunch core engine to become unresponsive, maybe in a loop until some timeout is reached?

A couple of other things I have noticed when the core host engine is unresponsive for 10 minutes:
- the summary view (see previous screenshot Engine delay: summary view during the delay) also becomes unresponsive and freezes on a previous state showing that build tasks are occurring, but from the task manager (see previous screenshot Engine delay: task manager during the delay) it is evident that no build host processes are performing any work
- if I close down Visual Studio 2017 the core host engine keeps chugging away in task manager for many minutes (I haven't timed it, but I suspect it would not disappear until the end of the 10 minutes - do you want me to confirm that?)

Kind regards,
Craig.
Remco
#20 Posted : Saturday, March 17, 2018 10:03:49 AM(UTC)
Rank: NCrunch Developer

Groups: Administrators
Joined: 4/16/2011(UTC)
Posts: 5,178

Thanks: 687 times
Was thanked: 827 time(s) in 787 post(s)
Hi Craig,

I'm sorry to hear that the build didn't solve the problem. I am, unfortunately, pitching blindly here as I haven't been able to reproduce the problem myself. It may not be reasonable for me to ask this, but if you're able to create a sample solution producing this problem that you can share with me, it would be a massive help in isolating the issue.

The fix in the above build won't have any affect on your test execution or timeouts. If this seems to have improved, this would certainly be coincidental.

Could you tell me if you're making use of any of the following features, and if so, to what extent?

- NCrunch.Framework.RequiresCapabilitiesAttribute
- NCrunch.Framework.ExclusivelyUsesAttribute/NCrunch.Framework.InclusivelyUsesAttribute
- NCrunch.Framework.SerialAttribute
- Disabling of parallel execution via configuration setting
- The 'Tests to execute on this machine' configuration setting (basically filtering of tests so that different machines run different sets of tests when working across a grid)

I'd ask to make sure you're completely certain in checking for the above, executing a text-search over your solution if you're not sure. The use of any of these options can have quite a significant effect on the code being used by the engine, so knowing this will help me rule out a range of possibilities. The current value of the 'Tests to execute on this machine' setting is quite suspect for me at the moment.
Users browsing this topic
Guest
2 Pages12>
Forum Jump  
You cannot post new topics in this forum.
You cannot reply to topics in this forum.
You cannot delete your posts in this forum.
You cannot edit your posts in this forum.
You cannot create polls in this forum.
You cannot vote in polls in this forum.

YAF | YAF © 2003-2011, Yet Another Forum.NET
This page was generated in 0.224 seconds.