Hi, thanks for sharing this issue.

Does this happen with every execution run? Are you using distributed processing?

Let's see what the log file can tell us!

Try:

NCrunch.exe -LogVerbosity Detailed > MyLog.txt

The log file will be very big, but the tail end of it could be very revealing. Look out for log messages at the end of the log related to 'EngineWorkCompletionMonitor'. This is a component responsible for monitoring the engine and informing it when the end-to-end run is complete. The messages it emits can often be useful in identifying where the engine has hung.

I am seeing lots of lines like these:
Line 179653: [14:25:17.5946-Core-120] Event [TaskProcessedEvent] is being published on thread CoreThread to subscriber: EngineWorkCompletionMonitor.
Line 179678: [14:25:17.6102-Core-120] Event [TaskProcessedEvent] is being processed on Core thread with subscriber: EngineWorkCompletionMonitor.
Line 179679: [14:25:17.6102-Core-120] EngineWorkCompletionMonitor: Rejecting work complete state because local tasks are still in progress
Line 180270: [14:26:27.3276-Core-49] Event [TaskProcessedEvent] is being published on thread CoreThread to subscriber: EngineWorkCompletionMonitor.
Line 180295: [14:26:27.3276-Core-49] Event [TaskProcessedEvent] is being processed on Core thread with subscriber: EngineWorkCompletionMonitor.
Line 180296: [14:26:27.3276-Core-49] EngineWorkCompletionMonitor: Rejecting work complete state because local tasks are still in progress

I realized as well, that another node was out of disk space. So I conducted an experiment, running on only 3 nodes (out of the 12), that didn't have any issues - and NCrunch finished nicely!

So, I must ask, if a node configured in the solution file has run out of space, or the node is not running in the first place, should they not just be ignored and processing done on the other available nodes?

This is a good catch and I can see how this would happen. When a client has work in the queue that it thinks can be processed by a grid node but the grid node is not working properly, the client will wait until the grid node becomes available and executes the work before it considers the run to be complete.

The key point of interest here is that the client should only do this if there is unprocessed work in the queue. So even if there are grid nodes offline or in some kind of half-state, the client should only sit waiting if there is work that only these nodes can process.

The nodes that were offline, did they have any special capabilities required by tests in your solution? I'm wondering why the unprocessed tasks weren't simply handed over to nodes that were working correctly.

It's possible that this is then actually an error handling problem on the node itself. If a node picked up some work from the client, then bugged out and failed to 'return' the work in any kind of state, the client would wait forever and the node would just sit in its failed state.

Do you have any record of the out of disk space error that was kicked up by your grid node? I'm wondering where in the chain this happened .. it's possible that it hit somewhere that the error wasn't handled the way it should have been.

v2.27 did include a change to the tracking of grid processing, making the client wait for 60 seconds before declaring the work 'done' if a grid node was disconnected. I don't think this change is responsible for the issue you've encountered - it's probably something that went wrong on the node itself.

Remco, I wouldn't post the log file publicly but I would be happy enough to send it to you privately, if you would like that?

Thanks for sending through the log.

According to the log, the console tool is not terminating the run because there is a task still being processed.

This could be one of the following:

1. A test that is taking an extraordinary long time to execute. Although NCrunch does have timeout settings, the method of enforcing these timeouts is not 100% reliable. Sometimes if a test is stalled while executing certain APIs or critical code blocks, NCrunch cannot interrupt it and it may hang forever.

2. A critical failure on a remote grid node that has caused it to 'swallow' the task without reporting it as failed or completed. I presently don't know of any scenarios in which this can happen, but I'm sure it's far from impossible. If you're having trouble with disk space on your nodes then this is definitely suspect.

3. A test task that has a long aggregate execution time (i.e. the tests within it between them just take a long time to run). I'm going to assume that this isn't the case for you because if it were, you likely would just be patient and wait for the run to complete and would not take the time to report the problem here.

There are two ways to get a better handle on what is happening here:

1. Enable logging on the grid nodes. If a node is dying silently because of internal problems, this should show up in its own log.

2. Trying doing some end-to-end runs with NCrunch over this solution using the NCrunch VS plugin instead of the console tool. Ensure you use the grid nodes. You can then use the NCrunch UI to analyse issues and identify which tests are stuck. In theory, if there is a grid or test processing issue that affects the console tool run, it should also affect NCrunch when it runs in VS.

Hi Csaba,

Thanks for sending through the node logs for this run.

I wasn't able to find any data in the log that showed this test finished its execution on the grid node. According to the log, the test execution started at 15:14:45 and the thread never came back.

I suspect that something is causing this test to hang. Does the test interact with anything outside of its own process? Is there any multithreaded code or complex conditions in the test that might cause a hang? Does the test run correctly if you execute it locally without the grid involved?

Good to hear that the build isn't hanging now, though as you've mentioned, this doesn't completely add up. I have a feeling that we haven't seen the last of this problem.

If you see the problem start appearing again, it may be worth trying to recreate it in a debug session so you can figure out where it's hanging. If the hanging patterns are too erratic to get a debugger on them, adding some logic to drop trace logs into a file may help to pinpoint exactly where in the code the hangups are.