After several months of living with this, I've inspected this issue a bit deeper.
Issue:
Having a large solution with about 150 projects and a developer machine with 16 cores and thus NCrunch with heavy multithreading, I've got a blocker many times. Asking my team members it seemed to be dependent on how many cores are used for the MSBuild building process.
Especially in the 'Run impacted tests automatically'-Mode it gets rather common:
Opening the solution or change any impacted file, the build starts running. After a short time, the CPU goes back to idle, while NCrunch states a high Engine Core Load, usually 97%. No further tests will be executed. The usual solution to this was to manually kill nCrunch.EngineHost, wipe some of the cache, etc and reenable NCrunch.
Research:
I've logged the whole build pipeline and found nothing special. But while debugging the EngineHost, besides many UnauthorizedAccessExceptions, one Exception happened quite before the blocker:
nCrunch.Compiler.Cil.Utility.CilResolutionFailedException
HResult=0x80131500
Message=The expected type with identifier '10241287978610504889' was not found in this assembly
Source=nCrunch.Compiler
StackTrace:
at nCrunch.Compiler.Cil.Types.CilExportedTypeTable.GetTypeById(UInt64 typeId)
Unfortunately this is the whole stack trace.
After some configuration fiddling, this is what I found out:
This only happens with massive multithreaded build, setting "Max number of processing threads" to "1" solves the problem, setting it to below 4 loosens it. So this is definitively a thread safety issue.
But more important: Setting "Impact detection mode" to "WatchText" solves the problem even without limiting the max number of processing threads. So this issue belongs to the "CompareIL" change detection mode.
Quick Fix for all users who currently have this issue:
Configuration -> Performance -> Set "Impact detection mode" to "WatchText"
Bugfix request:
The CilResolutionFailedException seems to happen whenever "Impact detection mode" is set to "CompareIL/default" and projects are built in parallel, losing their Type identifier. This seems to be a thread-safety issue or unhandled exception. It would be great to get rid of this build blocker whatever the solution might be.
Thanks for sharing this issue in so much detail. I appreciate how hard it must have been to extract this exception.
I agree that this looks like a race condition in the type resolver. I've reviewed the code involved and have a theory about what could be causing this. Unfortunately, I don't have a way to test it yet as it looks like the scope of the race is very narrow. I'd like to try implementing a codefix and arranging a build for you later this week. If the fix doesn't work, I might need to try and build some targeted tests that can surface the issue under load with heavy churning. I'll let you know as soon as I have the build available.
I think the easiest way to reproduce this exception for development is to change GetTypeById...) to always throw the exception or randomly throw it - even in a small solution.
But I'm glad to help and retest it with a build. :)
I've implemented a speculative fix for a possible race condition I've discovered in this this component. Would you be interested in trying the build below to see if it works better for you?
After a while of testing in CompareIL/default Mode and Run impacted tests:
It has gotten better - no exception thrown, no more hang during build & first full run.
But I still get the EngineHost hanging, especially in "Run pinned tests"-Mode even without having any pinned tests.
No, I havent found any other sides yet. Currently I've been only the default VS Debugger which only shows IL. But I'll keep my eyes open to gather more information.
Ok, I've got a snapshot in JetBrains dotTrace. Its quite small - 26MB zipped. Tell me if you need it.
It seems to lock on CoreDispatcher -> ClearProcesses -> TerminateProcess
while a StopUsingProcess in a Worker is already running, but tries to call TerminateProcess
Kelon wrote:
It seems to lock on CoreDispatcher -> ClearProcesses -> TerminateProcess
while a StopUsingProcess in a Worker is already running, but tries to call TerminateProcess
Thanks! This helps a great deal.
I've examined the code involved, and interestingly, this doesn't actually look like a deadlock. The code here has the potential to hang in one of two places:
1. The O/S is failing to fully terminate/cleanup the instance of a taskhost (i.e. nCrunch.TestHost.*.exe), and NCrunch is stuck in a loop waiting for the .EXE to terminate. I haven't seen this happen on my side under NCrunch, but it may depend on what the code under test is doing at the time the O/S tries to terminate the process. I would expect that there are critical service calls that the O/S must complete before the process can fully terminate. An example could be something like a background thread that runs during your test run that calls into some deep service routine that never comes out. It might be possible to figure this out by attaching a debugger to any nCrunch.TestHost.*.exe processes and examining what they're doing at the time the engine hangs.
2. You have an MSTest test that is holding file locks onto files copied to its internal MSTest sandbox directory, and this is happening on a large enough scale that the timeouts of 15 seconds per task instance are long enough to cause the perception of a hang. As you've mentioned you're not using MSTest, I don't think this applies to you. Just thought I'd mention it as it IS still a potential hang point.
It should be possible to examine both of the above cases by turning on your logging with a verbosity of Medium. When NCrunch tries to terminate a process, it logs the message 'Process XXXX is terminating'. The XXXX is the ID of the Windows process. If the log messages for the thread involved suddenly stop after this message, then you can be sure its the process with the specified ID that is failing to complete termination and is causing the hang.
Something that could be worth trying is to turn off the 'Terminate test runners on complete' setting. This won't resolve any problems caused by processes failing to terminate, but it will change the life cycle involved by pushing the termination later in the sequence and reducing the number of threads involved. It might provide you with a workaround.
I've tried 'Terminate test runners on complete':false
After several hours of coding, NCrunch stayed stable! :)
Your guess #1 sounds possible - I haven't debugged it yet. I'll try to find the responsible O/S handle... probably one of the IL Code generators. (Well, hopefully not!)