Hi, thanks for sharing this.

Can you try running with the node using a fresh project/solution built from one of the VS project templates? This will help to establish whether the problem is related to the configuration in your solution or whether it's something specific to the node.

Also, in the Distributed Processing Window, can you check what the reported Task Capacity is for the troublesome node?

Thanks for sharing these extra details.

Something that should help here is to turn on the "Required Capabilities" column in the Processing Queue Window (right click the column headers). This will show you which of the tasks have capabilities assigned to them and therefore won't be runnable on the nodes. Because NCrunch's configuration system is fairly complex, this will help you to identify projects that may have been assigned capabilities accidentally.

It's worth considering that when a project has a required capability, the node will be unable to build it and also unable to build any other project that depends on it. This means that assigning a capability to a project at the bottom of your dependency tree can cause the node to avoid building any projects in the solution.

It is normal behaviour for the processing queue to contain tasks that cannot be processed by nodes due to their required capabilities.

It's great to hear that's fixed the capabilities problem.

The problem you're describing with the batching has some similarities with another problem a user is currently reporting.

Basically, NCrunch uses the last reported passing execution time of a test to determine how it should batch the test for parallelization. Ideally, we'd want to place each test in its own 'batch' so that we have perfect concurrency. Unfortunately, the architecture of test frameworks doesn't really make this possible, as the overhead that goes with setting up the execution would make such an approach extremely inefficient. So what NCrunch does is group together large numbers of tests with very low execution times and run these inside a single batch/task. For this to work, NCrunch's expected execution time of each test needs to be fairly accurate. If a test has a normal execution time of 5 minutes but NCrunch thinks it will take 80ms, then it'll be batched with lots of other tests and the overall efficiency of the run with be degraded.

For NCrunch to lose track of a test's normal execution time, something must be causing this to happen. Is it possible you have something in your code that might trigger a rapid artificial pass of a long running test? Or do your tests have an extremely variable execution time? If you're having ongoing problems with this, there must be some kind of event repeating that is causing NCrunch to lose accurate track of the normal execution times of your tests.

I recommend turning on the 'Expected Execution Time' column in the Tests Window. This is the time that NCrunch uses when batching tests, so it's worth keeping an eye on it when trying to establish what is causing this problem.

You can also force NCrunch to place tests in their own batch. A test labelled with IsolatedAttribute will always run in its own task. The batching logic also factors in ExclusivelyUsesAttribute and InclusivelyUsesAttribute, as it isn't possible for tests within a batch to make different use of resources. If you have tests that are consistently long running, you can use these attributes to work around the problem.

OOOOH, hm, it seems that I've identified a use case where this happens: if an entire test fixture fails for some reason (in this case static setup for the test fixture), then every individual test in the fixture will fail very quickly. Upon the next attempt to run those failing tests, they'll all be batched in the same task, because the engine thinks they should be very fast executing tests.

I don't think this is the only situation where I run into this, but this is at least one of the situations. Is there any way I can mitigate this?

I might suggest that, if a test goes from passing to failing, then it probably makes more sense that the expected execution time should be based on the last time the test passed.

I'm using NUnit 3.13.2.

I can confirm that the tests that seem to cause the biggest problems don't have very expensive setup (relative to other tests that run fine). Actually, I just did a test run (they ran automatically as they were impacted by code changes). Three different fixtures ran, as three different tasks, containing 285, 291, and 286 tests. The Expected Processing Times on these tasks was 00:08:09.666, 00:08:23.093, and 00:14:57.182, respectively. The length of those expected times, alone, I would expect the engine to cause to be broken up into many parallel tasks. The interesting thing about these tasks is that the "Actual Processing Time" seemed to be WAY off, 00:40:24.300, 00:41:36.638, and 00:41:34.934. I wasn't keeping a sharp eye on the clock, but I think they must have finished in something much closer to the expected times. Also, the Expected vs Actual for the individual tests within those tasks seemed to match for most if not all.

I guess I should mention that we've built up a somewhat complex test infrastructure over the years, with TestBase<T>, UnitTest<T>, and Integration<Test> abstract base classes, which define abstract/virtual methods for overriding, and which get NUnit attribute decorations, for the purpose of centralizing structure and logic, and easily sharing behavior. Most every test fixture we have inherits from one of these base classes. This is just to point out that so many of the tests are doing a lot of the same setup logic, yet this problem only seems to affect a few fixtures.

The particular fixtures that are exhibiting this problem are themselves derived classes of a particular abstract base class that defines most of the actual test methods, which is why the test counts are so similar. This structure mirrors the structure of the production code classes, which have very similar structures, function, and constraints. So every tests defined in the base class is performed 3 times, once for each derived class. I wonder if this structure is somehow affecting how NCrunch is deciding to batch the tests within.

Another potential complication is that many of these tests are parameterized with a ValueSourceAttribute. These tests are checking, e.g., whether the expected behavior is exhibited for the current user when he has a specific role in the system, and so some of these tests could be run an upward of 30 times apiece. (This is much of the cause for those large total test counts.) I do expect that NCrunch may have to run a single parameterized test method up to X times in a single task. However, I definitely don't expect them all to run in a single task.

So there are some extra details to chew on. BTW, these are the same test fixtures that I mentioned in my last post about having failed quickly in a prior run. This time, all of these tests had succeeded in their prior run, so that's not the problem here (and may not be a problem at all).

I can export the NCrunch Tests window for you. But it appears that there is never any difference between the "Last Execution Time" and "Expected Execution Time" for any individual test. Also, I never see any execution times for fixtures on this window that seem to make any sense. I would expect them to be the sum of the individual tests, but they're always just values in the range of a few seconds, i.e. a value even lower than many of the individual test times.

It's on the NCrunch Processing Queue window that I get results that look to be more accurate, although, again, that window shows greatly differing results for Expected vs. Actual Processing Times.



The above is the result of running all of the tests in a particular project (I just clicked on the project name and Run selected test(s) in new process). This project contains 7 different fixtures, with a total of 973 tests, according to NCrunch. Three of those fixtures are as described in my previous post, inheriting from a single base class. Happily, most of those tests were well distributed, not just in running in different tasks, but also distributed across many nodes. However, one of those tasks contains 285 tests (what looks like an entire fixture). It was expected that this fixture would take 52 minutes to complete. It was accurately reported as taking about 30. The result of this was that most of the tests completed within probably 5-10 minutes. Then, a single task/thread spun and ran for an additional 20 minutes before I could receive any feedback on any of those 285 tests, while 40+ potential processes sat idle. I can confirm that all of these tests were passing previously, so there should probably not be much concern that the times were calculated to be artificially low (as a result of incorrectly fast-failing in a previous run).

Now, independent of whether it's correct that those 285 tests actually took 52 minutes to complete in a previous run, I would in no way expect that the engine might decide that we would want to run all of those tests sequentially, in a single task, especially if it thought it would take that long. Also, this is one of those 3 fixtures that inherits from the base test fixture. The other two fixtures had their 285+ tests distributed among different tasks and different nodes (although that's often not the case). So it doesn't seem like it could be the structure of those test classes that could be the cause of this, as they all share the same one. Also, these are pretty strictly "unit tests", in that database, file system, etc. are stubbed with in-memory implementations.

If we actually care about what the expected and actual processing times are: this is a single test run on a single project. Usually, these tests will be running with probably a few thousand other tests, including integration tests that will be hitting the file system, database, ElasticSearch index, and other slow infrastructure. So I could potentially see the system load alone being responsible for the tests taking much longer when all run together.

So...maybe the execution times are correct? I'm not sure it matters. From what I'm seeing in this test run, I respectfully submit that there may just be something in the batching logic that needs refining.

I do not use AtomicAttribute anywhere.

Would you be interested in trying the build below? This includes the above mentioned fix for the batching:

NCrunch_Console_4.14.0.2.msi
NCrunch_Console_4.14.0.2.zip
NCrunch_GridNodeServer_4.14.0.2.msi
NCrunch_GridNodeServer_4.14.0.2.zip
NCrunch_LicenseServer_4.14.0.2.zip
NCrunch_VS2010_4.14.0.2.msi
NCrunch_VS2010_4.14.0.2.zip
NCrunch_VS2012_4.14.0.2.msi
NCrunch_VS2012_4.14.0.2.zip
NCrunch_VS2013_4.14.0.2.msi
NCrunch_VS2013_4.14.0.2.zip
NCrunch_VS2015_4.14.0.2.msi
NCrunch_VS2015_4.14.0.2.msi.7z
NCrunch_VS2015_4.14.0.2.zip
NCrunch_VS2017_4.14.0.2.msi
NCrunch_VS2017_4.14.0.2.msi.7z
NCrunch_VS2017_4.14.0.2.zip
NCrunch_VS2019_4.14.0.2.msi
NCrunch_VS2019_4.14.0.2.msi.7z
NCrunch_VS2019_4.14.0.2.zip
NCrunch_VS2022_4.14.0.2.msi
NCrunch_VS2022_4.14.0.2.msi.7z
NCrunch_VS2022_4.14.0.2.zip

Note that this build includes grid protocol changes, so you'll need to update your nodes if you want to use them with the newer client.

Excellent! Thanks for confirming this :)



Keep an eye out. If you can find a way to reproduce other pipeline issues, I'll be happy to take a closer look.