Hi Ralf,

The problem with this approach is that the pipeline is very dynamic. NCrunch can't accurately predict how long some tasks will take, so it relies on an approach where grid nodes and the local engine each 'pull' tasks out of the queue as their resources become available.

At the moment the only way to get a picture of what is happening in the NCrunch is to examine the processing queue while the engine is working. If you set the filters to only show tasks that are being executed, this will allow you to see which tasks are being sent to the nodes and which tasks are holding up the queue.

Hi Ralf,

I wonder if the best way to handle this may be to use the NCrunch logs.

If you set Log Verbosity to Medium (or perhaps High, depending on the detail you need) and set Log To Output Window to True, NCrunch will dump a ton of data in the VS output window.

Sifting through this manually would be very painful for a big grid run, but you could use a Regex to slice up the data to retrieve the start and end points of each of the execution tasks. Because each of the messages is time stamped, it is theoretically possible to extract this data .. though it might require some effort.

There is actually a work in progress in the NCrunch engine to perform detailed performance monitoring over individual test runs with the intention of doing this sort of tuning. With instability in the ecosystem (new VS, new NUnit, new Xunit) it's tough to say when I'll be able to release this .. but we are moving in this direction.

Hi Ralf,

I was waiting for someone to ask this question, and I'm glad you did, as it means someone is getting some good use of this feature :)

(not specified) basically means 'I don't know'. When NCrunch constructs the performance tracking chart, it correlates every task performed by the engine in pursuit of the end goal (the reporting of the test result). An effort was made to make sure that every significant task is correctly labelled and tracked, but there are always cracks. It wasn't possible to include much of the internal plumbing of the engine (of which the impact is usually negligible).

Also, because of the level of concurrency, the engine can actually be tied up doing other work for tasks completely unrelated to the end goal. For example, the engine may be busy merging code coverage data from a different test run, and is therefore unable to allocate the resources to perform other tasks. These situations then show as gaps of '(not specified)'.

I'm hoping that the gaps you're observing aren't big ones. If they are, we should investigate further.

Hi, what would candidate as "big" here? Is 14s like this one a non-big one? :)



Thanks.

Hi GreenMoose,

I had similar gaps all over my tests and saw them regularly. I came to the conclusion that I completely overloaded my engine.

My grid nodes have approx. 8 logical CPU cores and I had set the task capacity to 16 (so for each grid nodes I doubled the task capacity based on its logical CPU cores) , mainly to reduce the build times. As a result my engine was overloaded but based on the nature of my tests that gave me the max. throughput.

As I've seen those gaps I thought that they exist probably due to garbage collection, thread scheduling, context switching etc.
So I reduced the task capacity for each grid node back to the number of logical CPU cores. In some situations that's kind of "suboptimal" but the overall throughput loss is approx 5 seconds or so at maximum, so it's acceptable for me.
The reason is that my long-running tests now no longer run that long (eg. a test that has run for 20 seconds now takes only 10 seconds); so the reduction in task capacity led to a speed-up of test duration and the overall duration is almost the same.

However, the large gaps are gone now.

I'm not sure who you use the grid resp. how you configured your grid nodes but maybe that's worth looking at. Actually, when I did that I was surprised on the results.


Best regards,
Ralf

The 14 second delay in this situation would likely have been caused by an internal task (or series of tasks) tying up the engine's main thread over an extended period of time.

In my understanding of the design of the engine, it's unlikely that this could be the result of over allocating and is more likely to be due to something internal taking much longer than it should be. So basically, I think it's a defect. The hard part will be identifying steps to reproduce it.

I currently am aware of three ways in which the engine can be overloaded:
1. During initialisation (unavoidable and always temporary)
2. When running a large number of tests with high coverage spread that have never been executed before (i.e. first time run with no cache file)
3. When using the risk/progress indicator with a high number of tests and processing threads (this feature doesn't scale well).