Slower IDispatch calls in compare to .NET Framework.

[vladimir-cheverdyuk-altium]

We are porting our application from .NET Framework to .NET 6 and we have system of plugins that using IDispatch to call the native code.

Interface in C# declared like this:

[InterfaceType(ComInterfaceType.InterfaceIsIDispatch),
Guid("00020400-0000-0000-C000-000000000046")]
public interface IMyIntf
{
    [DispId(DispConsts.SomeFuncId)]
    void SomeFunc();
}

During the performance tests of one of our plugin I found that it is slower than the same version in .NET Framework. After checking in PerfView I found this callstack in .NET Framework:

Name
 clr!CLRToCOMLateBoundWorker
+ clr!MethodDescCallSite::CallTargetWorker
...

And total time for clr!CLRToCOMLateBoundWorker is 26.123 seconds There are a few more functions that clr!CLRToCOMLateBoundWorker calls that they are less than 500ms each.

And this callstack for .NET 6

Name
 coreclr!CLRToCOMLateBoundWorker
+ coreclr!MethodDescCallSite::CallTargetWorker
+ coreclr!Module::GetPropertyInfoForMethodDef
...

And total time for clr!CLRToCOMLateBoundWorker is 28.290 seconds

Basically there is no call for coreclr!Module::GetPropertyInfoForMethodDef in .NET Framework and this call consumes in .NET 6
about 7.509 seconds out of 28.290.

If I got it right the source of problem is here:

HRESULT MDInternalRW::GetPropertyInfoForMethodDef(  // Result.
    mdMethodDef md,                     // [IN] memberdef
    mdProperty  *ppd,                   // [OUT] put property token here
    LPCSTR      *pName,                 // [OUT] put pointer to name here
    ULONG       *pSemantic)             // [OUT] put semantic here
{
....
    ridMax = m_pStgdb->m_MiniMd.getCountMethodSemantics();
    for (ridCur = 1; ridCur <= ridMax; ridCur++)
    {
        IfFailGo(m_pStgdb->m_MiniMd.GetMethodSemanticsRecord(ridCur, &pSemantics));
        if (md == m_pStgdb->m_MiniMd.getMethodOfMethodSemantics(pSemantics))

I put breakpoint there and ridMax is 0x33F and it looks like each IDispatch call will loop 831 times in this function and found nothing because there are no properties in this assembly. Just in case I put breakpoint in body of that IF and it never stops there.

My question am I correct about this? If yes, is it possible to mitigate it somehow?

I checked .NET 8 source code and it looks mostly the same. I cannot verify it on .NET 8 because one of 3rd party assemblies we use is not compatible with .NET 8 yet.

Thank you.

[jkotas]

MDInternalRW::GetPropertyInfoForMethodDef

Presence of this method in the profile means that the module metadata was switched to a writeable mode that is much slower. The read-only version of the same method is optimized using binary search

runtime/src/coreclr/md/runtime/mdinternalro.cpp

Lines 1933 to 1962 in 9da5359

	// Lazy initialization of m_pMethodSemanticsMap
	if ((ridMax > 10) && (m_pMethodSemanticsMap == NULL))
	{
	NewArrayHolder<CMethodSemanticsMap> pMethodSemanticsMap = new (nothrow) CMethodSemanticsMap[ridMax];
	if (pMethodSemanticsMap != NULL)
	{
	// Fill the table in MethodSemantics order.
	for (ridCur = 1; ridCur <= ridMax; ridCur++)
	{
	IfFailRet(m_LiteWeightStgdb.m_MiniMd.GetMethodSemanticsRecord(ridCur, &pSemantics));
	tk = m_LiteWeightStgdb.m_MiniMd.getMethodOfMethodSemantics(pSemantics);
	pMethodSemanticsMap[ridCur-1].m_mdMethod = tk;
	pMethodSemanticsMap[ridCur-1].m_ridSemantics = ridCur;
	}
	// Sort to MethodDef order.
	CMethodSemanticsMapSorter sorter(pMethodSemanticsMap, ridMax);
	sorter.Sort();
	if (InterlockedCompareExchangeT<CMethodSemanticsMap *>(
	&m_pMethodSemanticsMap, pMethodSemanticsMap, NULL) == NULL)
	{ // The exchange did happen, suppress of the allocated map
	pMethodSemanticsMap.SuppressRelease();
	}
	}
	}
	// Use m_pMethodSemanticsMap if it has been built.
	if (m_pMethodSemanticsMap != NULL)
	{
	CMethodSemanticsMapSearcher searcher(m_pMethodSemanticsMap, ridMax);

.

You can try setting a breakpoint at ConvertMDInternalImport in unmanaged debugger to see what triggers the switch to writeable mode. There are several possible triggers for this switch - make sure to find the right one for the module in question in case there are multiple. Once you find the stacktrace of the trigger, we should be able to come up with a mitigation.

[vladimir-cheverdyuk-altium]

Hi @jkotas. Thank you for prompt response.

Ok, I put breakpoint in place you mentioned, then I did step out in debugger and inspect this->m_identity->m_path.m_asStr. It looks like call stack for assembly in question is here:

coreclr!PEFile::ConvertMDInternalToReadWrite+0x112 [D:\a\_work\1\s\src\coreclr\vm\pefile.cpp @ 718] 
coreclr!PEFile::OpenImporter+0xe [D:\a\_work\1\s\src\coreclr\vm\pefile.cpp @ 673] 
coreclr!PEFile::GetRWImporter+0x11 [D:\a\_work\1\s\src\coreclr\vm\pefile.inl @ 444] 
coreclr!Module::GetRWImporter+0x15 [D:\a\_work\1\s\src\coreclr\vm\ceeload.h @ 1887] 
coreclr!Module::GetReadablePublicMetaDataInterface+0x99 [D:\a\_work\1\s\src\coreclr\vm\ceeload.cpp @ 3303] 
coreclr!Module::GetISymUnmanagedReader+0x747 [D:\a\_work\1\s\src\coreclr\vm\ceeload.cpp @ 3491] 
coreclr!Module::GetISymUnmanagedReaderNoThrow+0x72 [D:\a\_work\1\s\src\coreclr\vm\ceeload.cpp @ 3337] 
coreclr!DebugStackTrace::GetStackFramesInternal+0xa83 [D:\a\_work\1\s\src\coreclr\vm\debugdebugger.cpp @ 553] 
System_Private_CoreLib!System.Diagnostics.StackFrameHelper::InitializeSourceInfo(System.Int32, System.Boolean, System.Exception)$##600641B+0x42
System_Private_CoreLib!System.Diagnostics.StackTrace::CaptureStackTrace(System.Int32, System.Boolean, System.Exception)$##600642B+0x42
System_Private_CoreLib!System.Diagnostics.StackTrace::.ctor(System.Int32, System.Boolean)$##600642F+0x17
0x00007ffc`f406dd6f
coreclr!CallDescrWorkerInternal+0x83
coreclr!DispatchCallSimple+0x80 [D:\a\_work\1\s\src\coreclr\vm\callhelpers.cpp @ 220] 
coreclr!ExceptionNotifications::DeliverExceptionNotification+0x46 [D:\a\_work\1\s\src\coreclr\vm\excep.cpp @ 11053] 
coreclr!ExceptionNotifications::DeliverNotificationInternal+0x14f [D:\a\_work\1\s\src\coreclr\vm\excep.cpp @ 11273] 
coreclr!ExceptionNotifications::DeliverNotification+0x13 [D:\a\_work\1\s\src\coreclr\vm\excep.cpp @ 11181] 
coreclr!ExceptionNotifications::DeliverFirstChanceNotification+0xa4d8f [D:\a\_work\1\s\src\coreclr\vm\excep.cpp @ 11325] 
coreclr!ExceptionTracker::ProcessManagedCallFrame+0x566 [D:\a\_work\1\s\src\coreclr\vm\exceptionhandling.cpp @ 2605] 
coreclr!ExceptionTracker::ProcessOSExceptionNotification+0x317 [D:\a\_work\1\s\src\coreclr\vm\exceptionhandling.cpp @ 1937] 
coreclr!ProcessCLRException+0x21c [D:\a\_work\1\s\src\coreclr\vm\exceptionhandling.cpp @ 1066] 
ntdll!RtlpExecuteHandlerForException+0xf
ntdll!RtlDispatchException+0x244
ntdll!KiUserExceptionDispatch+0x2e
KERNELBASE!RaiseException+0x69
coreclr!RaiseTheExceptionInternalOnly+0x28a [D:\a\_work\1\s\src\coreclr\vm\excep.cpp @ 2806] 
coreclr!UnwindAndContinueRethrowHelperAfterCatch+0x35 [D:\a\_work\1\s\src\coreclr\vm\excep.cpp @ 8216] 
coreclr!AssemblyNative::LoadFromPath+0x141f36 [D:\a\_work\1\s\src\coreclr\vm\assemblynative.cpp @ 290] 
System_Private_CoreLib!System.Runtime.Loader.AssemblyLoadContext::LoadFromPath(System.IntPtr, System.String, System.String, System.Runtime.CompilerServices.ObjectHandleOnStack)$##6003B38+0x86
System_Private_CoreLib!System.Reflection.Assembly System.Runtime.Loader.AssemblyLoadContext::LoadFromAssemblyPath(System.String)$##6003B74+0x95
System_Private_CoreLib!System.Reflection.Assembly System.Reflection.Assembly::LoadFrom(System.String)$##6005219+0x16f
System_Private_CoreLib!System.Reflection.Assembly System.Reflection.Assembly::LoadFromResolveHandler(System.Object, System.ResolveEventArgs)$##6005218+0x185
System_Private_CoreLib!System.Reflection.RuntimeAssembly System.Runtime.Loader.AssemblyLoadContext::InvokeResolveEvent(System.ResolveEventHandler, System.Reflection.RuntimeAssembly, System.String)$##6003B8A+0x9c
System_Private_CoreLib!System.Reflection.RuntimeAssembly System.Runtime.Loader.AssemblyLoadContext::OnAssemblyResolve(System.Reflection.RuntimeAssembly, System.String)$##6003B89+0x25
coreclr!CallDescrWorkerInternal+0x83
coreclr!MethodDescCallSite::CallTargetWorker+0x176 [D:\a\_work\1\s\src\coreclr\vm\callhelpers.cpp @ 551] 
coreclr!MethodDescCallSite::Call_RetOBJECTREF+0x18 [D:\a\_work\1\s\src\coreclr\vm\callhelpers.h @ 461] 
coreclr!AppDomain::RaiseAssemblyResolveEvent+0x152 [D:\a\_work\1\s\src\coreclr\vm\appdomain.cpp @ 4972] 
coreclr!AppDomain::TryResolveAssemblyUsingEvent+0x7f [D:\a\_work\1\s\src\coreclr\vm\appdomain.cpp @ 4150] 
coreclr!AppDomain::PostBindResolveAssembly+0x5f [D:\a\_work\1\s\src\coreclr\vm\appdomain.cpp @ 3928] 
coreclr!AppDomain::BindAssemblySpec+0x47c [D:\a\_work\1\s\src\coreclr\vm\appdomain.cpp @ 4025] 
coreclr!PEFile::LoadAssembly+0xbe [D:\a\_work\1\s\src\coreclr\vm\pefile.cpp @ 1479] 
coreclr!Module::LoadAssembly+0x10c [D:\a\_work\1\s\src\coreclr\vm\ceeload.cpp @ 4670] 
coreclr!Assembly::FindModuleByTypeRef+0x332 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1083] 
coreclr!ClassLoader::LoadTypeDefOrRefThrowing+0x289 [D:\a\_work\1\s\src\coreclr\vm\clsload.cpp @ 2612] 
coreclr!MemberLoader::GetDescFromMemberRef+0x332 [D:\a\_work\1\s\src\coreclr\vm\memberload.cpp @ 295] 
coreclr!CEEInfo::resolveToken+0xcf6 [D:\a\_work\1\s\src\coreclr\vm\jitinterface.cpp @ 1164] 
clrjit!Compiler::impImportBlockCode+0x2c0 [D:\a\_work\1\s\src\coreclr\jit\importer.cpp @ 14628] 

0x00007ffc`f406dd6f is this code:

        private static void ProcessFirstChanceException(object sender, FirstChanceExceptionEventArgs e)
        {
             ...
                    var exception = e.Exception;
                    var exceptionStackTrace = new StackTrace(2, true); // Skip 2 frames: This method and exception method (present in exception trace)
                    exception.Source = ReportBuilder.GetExtendedExceptionSource(exception, exceptionStackTrace);

So my understanding is following:

1. During code compilation compiler found that we need to load some assembly that is referenced from code
2. AssemblyLoadContext::OnAssemblyResolve will try to load assembly from all probing path throwing exception after each try. This in turn will call ProcessFirstChanceException
3. ProcessFirstChanceException will add stack trace to exception.Source. This is necessary if we need to process this exception later in native code and display crash dialog if it is unhandled. It is somebody else code and I don't know all details. Please let me know if you need them.

I can confirm that if I remove AppDomain.CurrentDomain.FirstChanceException += ProcessFirstChanceException; then it works about 30% faster.

If I understand code correctly coreclr!Module::GetReadablePublicMetaDataInterface by some reason needs to create RW version when it should use RO. But maybe I'm wrong here.

[jkotas]

This is known issue #90563. The fix is being worked on in #93902. cc @hoyosjs

The issue is triggered by old Windows-style (aka full or non-portable .pdbs) being used to provide file names and line numbers in the formatted stacktrace.

Any one of the following is going to avoid the issue:

• deleting the .pdb from your deployed app
  or
• compiling the assembly with portable .pdbs (https://learn.microsoft.com/en-us/dotnet/csharp/language-reference/compiler-options/code-generation#debugtype)
  or
• avoiding the code path that creates stacktrace with file names and line numbers (what you have done by removing ProcessFirstChanceException)

[ghost]

Tagging subscribers to this area: @tommcdon
See info in area-owners.md if you want to be subscribed.

Issue Details

---

We are porting our application from .NET Framework to .NET 6 and we have system of plugins that using IDispatch to call the native code.

Interface in C# declared like this:

[InterfaceType(ComInterfaceType.InterfaceIsIDispatch),
Guid("00020400-0000-0000-C000-000000000046")]
public interface IMyIntf
{
    [DispId(DispConsts.SomeFuncId)]
    void SomeFunc();
}

During the performance tests of one of our plugin I found that it is slower than the same version in .NET Framework. After checking in PerfView I found this callstack in .NET Framework:

Name
 clr!CLRToCOMLateBoundWorker
+ clr!MethodDescCallSite::CallTargetWorker
...

And total time for clr!CLRToCOMLateBoundWorker is 26.123 seconds There are a few more functions that clr!CLRToCOMLateBoundWorker calls that they are less than 500ms each.

And this callstack for .NET 6

Name
 coreclr!CLRToCOMLateBoundWorker
+ coreclr!MethodDescCallSite::CallTargetWorker
+ coreclr!Module::GetPropertyInfoForMethodDef
...

And total time for clr!CLRToCOMLateBoundWorker is 28.290 seconds

Basically there is no call for coreclr!Module::GetPropertyInfoForMethodDef in .NET Framework and this call consumes in .NET 6
about 7.509 seconds out of 28.290.

If I got it right the source of problem is here:

HRESULT MDInternalRW::GetPropertyInfoForMethodDef(  // Result.
    mdMethodDef md,                     // [IN] memberdef
    mdProperty  *ppd,                   // [OUT] put property token here
    LPCSTR      *pName,                 // [OUT] put pointer to name here
    ULONG       *pSemantic)             // [OUT] put semantic here
{
....
    ridMax = m_pStgdb->m_MiniMd.getCountMethodSemantics();
    for (ridCur = 1; ridCur <= ridMax; ridCur++)
    {
        IfFailGo(m_pStgdb->m_MiniMd.GetMethodSemanticsRecord(ridCur, &pSemantics));
        if (md == m_pStgdb->m_MiniMd.getMethodOfMethodSemantics(pSemantics))

I put breakpoint there and ridMax is 0x33F and it looks like each IDispatch call will loop 831 times in this function and found nothing because there are no properties in this assembly. Just in case I put breakpoint in body of that IF and it never stops there.

My question am I correct about this? If yes, is it possible to mitigate it somehow?

I checked .NET 8 source code and it looks mostly the same. I cannot verify it on .NET 8 because one of 3rd party assemblies we use is not compatible with .NET 8 yet.

Thank you.

Author:	vladimir-cheverdyuk-altium
Assignees:	-
Labels:	tenet-performance, area-Diagnostics-coreclr, area-Interop-coreclr, untriaged
Milestone:	-

[vladimir-cheverdyuk-altium]

Hi @jkotas

I checked and there are no .pdb files, but that assembly itself compiled for .NET Framework and loaded into .NET 6 runtime. Can this create this issue? I can recompile it using /p:DebugType=portable

[jkotas]

Ah ok, maybe deleting the file is not sufficient. Yes, recompiling with /p:DebugType=portable should workaround the issue. (Also, /p:DebugType=portable works on current .NET Framework too.)

[vladimir-cheverdyuk-altium]

Hi @jkotas

It looks like we will be able to remove new StackTrace(2, true) as it is obsolete. Instead we grab whole stack and then analyze it rebuilding native and managed call stack.

But if you interested, we changed how we build out product and created build with portable PDB and problem is still there. From what I see call stack is the same but variable fPortablePDB is set to true in coreclr!DebugStackTrace::GetStackFramesInternal+0x1509 [D:\a\_work\1\s\src\coreclr\vm\debugdebugger.cpp @ 720] for that assembly. I also checked PDB file itself from symbols server and starts with BSJB.

From my understanding there is still call to ReleaseHolder<ISymUnmanagedReader> pISymUnmanagedReader( pModule->GetISymUnmanagedReaderNoThrow()); but pISymUnmanagedReader is NULL after it returns.

[jkotas]

variable fPortablePDB is set to true

If fPortablePDB is set to true, you should not be going down the coreclr!Module::GetISymUnmanagedReaderNoThrow that ended up triggering the conversion since it is under if (!fPortablePDB).

Maybe these is another path that triggers the RO->RW conversion in your app, that does not involve GetISymUnmanagedReaderNoThrow?

[vladimir-cheverdyuk-altium]

@jkotas It looks like it is problem in .NET 6 code. In that version call to GetISymUnmanagedReaderNoThrow pretty much unconditional. But in .NET 8 there is code that first check if PE Image has portable PDB and calls GetISymUnmanagedReaderNoThrow only if this is not portable PDB.

[jkotas]

For reference, this was fixed in #68990

[vladimir-cheverdyuk-altium]

Thank you for your help. I think issue is solved and I will close it. I hope we can migrate to .NET 8 soon :)