[mono] Deadlock on mono_loader_lock in mono_class_create_from_typedef

[uweigand]

We've seen a deadlock in msbuild when performing a source-build of rc2 natively on s390x (using the Mono runtime). In a nutshell, the deadlock occurs due to a lock-order inversion between the Mono JIT's mono_loader_lock and the managed Microsoft.Build.BackEnd.Logging.LoggingService._lockObject.

Specifically, we have two involved threads, the main thread and a thread pool thread.

The main thread runs

• NuGet.Build.Tasks.Console.Program:Main which calls
• NuGet.Build.Tasks.Console.MSBuildStaticGraphRestore:LoadProjects which calls
• Microsoft.Build.Evaluation.ProjectCollection:.ctor which calls
• Microsoft.Build.BackEnd.Logging.LoggingService:RegisterLogger which TAKES Microsoft.Build.BackEnd.Logging.LoggingService._lockObject and calls
• Microsoft.Build.Evaluation.ProjectCollection/ReusableLogger:RegisterForEvents
• At this point, the JIT compiler for Microsoft.Build.BackEnd.Logging.EventSourceSink:add_BuildStarted gets invoked
• This calls at some point mono_class_create_from_typedef which TAKES mono_loader_lock
• And deadlocks here

The thread pool thread runs

• NuGet.Build.Tasks.Console.ConsoleLoggingQueue:Process which calls
• NuGet.Build.Tasks.ConsoleOutLogMessage:ToJson which calls
• System.Collections.Concurrent.ConcurrentDictionary'2<TKey_REF, TValue_REF>:GetOrAdd
• At this point, the JIT compiler for Newtonsoft.Json.Serialization.DefaultContractResolver:CreateContract gets invoked
• This calls at some point mono_class_create_from_typedef which TAKES mono_loader_lock
• And calls mono_metadata_interfaces_from_typedef_full, which loads for the first time System.Linq.Expressions.dll
• This invokes the assembly load hook chain, in particular calling
• Microsoft.Build.BackEnd.Components.RequestBuilder.AssemblyLoadsTracker:CurrentDomainOnAssemblyLoad which calls
• Microsoft.Build.BackEnd.Logging.LoggingService:ProcessLoggingEvent which TAKES Microsoft.Build.BackEnd.Logging.LoggingService._lockObject
• And deadlocks here

It seems to me the root cause of the deadlock is that mono_class_create_from_typedef holds mono_loader_lock across function calls that may trigger invoking managed code (the assembly load hooks) which might do anything - this doesn't seem a good idea.

CC - @directhex @lambdageek @vargaz @akoeplinger
FYI - @giritrivedi @alhad-deshpande @janani66 @omajid @tmds

[lambdageek]

It seems to me the root cause of the deadlock is that mono_class_create_from_typedef holds mono_loader_lock across function calls that may trigger invoking managed code (the assembly load hooks) which might do anything - this doesn't seem a good idea.

Good catch!

[lambdageek]

Related to / duplicate of #51864

This is hard

[lambdageek]

@uweigand this will be quite tricky to fix and I think even if we put something together, it is highly unlikely that we will backport the fix in upstream net8.0 as it's bound to be risky (any time we make big changes to class-init.c we uncover issues with the change).

I would encourage, to whatever extent possible, to fix this in user code by rearranging the calling code to trigger assembly loading early. (I realize in this case I'm proposing that you change MSBuild... sorry.)

[Vishwanatha-HD]

I did reproduce the hang issue on dotnet 8 on different Redhat beaker machines with different RHEL distros.

I was able to reproduce for around 10 or 12 hang situations and in each of the case, when I attached gdb and looked at the backtrace information, I see the same backtrace as attached in the file..

I did work with Ulrich and local team in IBM, and Ulrich helped us to figure out that its the exact same issue as this one.

I have attached the logfile with all the details of all the process and threads backtrace..
dotnet_8_hang_issue_gdb_all_proc_info.txt

[uweigand]

@Vishwanatha-HD has now found an instance of this deadlock in the .NET 6 source-build. Unfortunately, while one of the involved locks is also the mono_loader_lock, the other involved lock is a different one; not a Microsoft.Build.BackEnd.Logging.LoggingService._lockObject, but rather an _lock object inside the implementation of ArrayPool<byte>.Shared in the runtime.

Again, we have a deadlock between two of msbuild's threads, this time a dedicated event logging thread and some thread pool thread.

The event logging thread

• handles some event via Microsoft.Build.BackEnd.Logging.LoggingService:RouteBuildEvent
• which in the end boils down to a System.IO.BinaryWriter:Write (string) call
• which has a "fast UTF-8" shortcut using a temporary buffer allocated via ArrayPool<byte>.Shared.Rent and returned via ArrayPool<byte>.Shared.Return
• Shared.Return stores the returned buffer for re-use in a per-thread pool, which on first invocation is initialized by InitializeTlsBucketsAndTrimming
• the latter calls ConditionalWeakTable::Add on its _allTlsBuckets variable
• and Add TAKES an internal _lock object
• while holding this lock object, we call some more routines, one of which is not yet JITted
• so Mono calls mono_jit_compile_method, which TAKES the mono_loader_lock, where we deadlock

The thread pool thread

• is initializing by calling Microsoft.Build.BackEnd.AssemblyTaskFactory:InitializeFactory
• which loads the task via Microsoft.Build.Shared.TypeLoader:Load
• which in a subroutine calls Microsoft.Build.Shared.TypeLoader/AssemblyInfoToLoadedTypes:ScanAssemblyForPublicTypes
• which loads the assembly via a non-default Microsoft.Build.Shared.MSBuildLoadContext and then inspects it via System.Reflection.RuntimeAssembly:GetExportedTypes
• which is implemented as a Mono intrinsic, which in a subroutine calls mono_class_create_from_typedef
• which TAKES the mono_loader_lock
• and then calls mono_class_get_checked, which ends up calling mono_alc_invoke_resolve_using_load
• which calls the non-default handler Microsoft.Build.Shared.MSBuildLoadContext:Load installed above
• which performs various file system checks via System.IO.File:Exists
• which on Linux ends up calling Interop.Sys.LStat
• which creates and disposes of a ValueUtf8Converter to perform string marshalling
• which uses a temporary Array<byte>.Shared buffer, and the dispose operation calls Return on it
• and as above, Shared.Return calls InitializeTlsBucketsAndTrimming
• which TAKES the internal lock object of _allTlsBuckets via ConditionalWeakTable::Add and deadlocks