From 71025f5f45089750be617163b230bcee307a20d8 Mon Sep 17 00:00:00 2001 From: Tomas Rylek Date: Fri, 17 Nov 2023 01:46:55 +0100 Subject: [PATCH 1/7] Instrumentation for measuring type and assembly load times --- src/coreclr/vm/appdomain.cpp | 20 ++++ src/coreclr/vm/clsload.cpp | 7 +- src/coreclr/vm/corhost.cpp | 8 ++ src/coreclr/vm/methodtablebuilder.cpp | 136 ++++++++++++++++++++++++++ 4 files changed, 170 insertions(+), 1 deletion(-) diff --git a/src/coreclr/vm/appdomain.cpp b/src/coreclr/vm/appdomain.cpp index 51aec1b9e1c69..eaff46eb002b5 100644 --- a/src/coreclr/vm/appdomain.cpp +++ b/src/coreclr/vm/appdomain.cpp @@ -2559,9 +2559,26 @@ CHECK AppDomain::CheckCanExecuteManagedCode(MethodDesc* pMD) #endif // !DACCESS_COMPILE +static int64_t AssemblyLoadCallCount = 0; +static int64_t AssemblyLoadTickCount = 0; + +int64_t GetPreciseTickCount(); +void DumpTimingInfo(const char *action, int64_t callCount, int64_t tickCount); + +void DumpAssemblyLoadTimingInfo() +{ +#ifndef DACCESS_COMPILE + DumpTimingInfo("AppDomain::LoadDomainAssembly", AssemblyLoadCallCount, AssemblyLoadTickCount); +#endif +} + void AppDomain::LoadDomainAssembly(DomainAssembly *pFile, FileLoadLevel targetLevel) { +#ifndef DACCESS_COMPILE + int64_t startTicks = GetPreciseTickCount(); +#endif + CONTRACTL { if (FORBIDGC_LOADER_USE_ENABLED()) NOTHROW; else THROWS; @@ -2602,6 +2619,9 @@ void AppDomain::LoadDomainAssembly(DomainAssembly *pFile, LoadDomainAssembly(pLockEntry, targetLevel); } + InterlockedAdd64(&AssemblyLoadTickCount, GetPreciseTickCount() - startTicks); + InterlockedIncrement64(&AssemblyLoadCallCount); + #else // DACCESS_COMPILE DacNotImpl(); #endif // DACCESS_COMPILE diff --git a/src/coreclr/vm/clsload.cpp b/src/coreclr/vm/clsload.cpp index ae4aa4f71c9f3..b5aea64c9f37b 100644 --- a/src/coreclr/vm/clsload.cpp +++ b/src/coreclr/vm/clsload.cpp @@ -3232,13 +3232,15 @@ static void PushFinalLevels(TypeHandle typeHnd, ClassLoadLevel targetLevel, cons } +int64_t GetPreciseTickCount(); +void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks); + // TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, TypeHandle typeHnd, ClassLoadLevel targetLevel/*=CLASS_LOADED*/, const InstantiationContext *pInstContext/*=NULL*/) { - CONTRACTL { INSTANCE_CHECK; @@ -3265,6 +3267,7 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, #if defined(FEATURE_EVENT_TRACE) UINT32 typeLoad = ETW::TypeSystemLog::TypeLoadBegin(); #endif + int64_t startTicks = GetPreciseTickCount(); ClassLoadLevel currentLevel = typeHnd.IsNull() ? CLASS_LOAD_BEGIN : typeHnd.GetLoadLevel(); ClassLoadLevel targetLevelUnderLock = targetLevel < CLASS_DEPENDENCIES_LOADED ? targetLevel : (ClassLoadLevel) (CLASS_DEPENDENCIES_LOADED-1); @@ -3279,6 +3282,8 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, PushFinalLevels(typeHnd, targetLevel, pInstContext); + RecordTypeLoadTime(typeHnd, GetPreciseTickCount() - startTicks); + #if defined(FEATURE_EVENT_TRACE) if (ETW_EVENT_ENABLED(MICROSOFT_WINDOWS_DOTNETRUNTIME_PROVIDER_DOTNET_Context, TypeLoadStop)) { diff --git a/src/coreclr/vm/corhost.cpp b/src/coreclr/vm/corhost.cpp index b85331e00ce8d..e72355369c08d 100644 --- a/src/coreclr/vm/corhost.cpp +++ b/src/coreclr/vm/corhost.cpp @@ -837,6 +837,10 @@ STDMETHODIMP CorHost2::UnloadAppDomain(DWORD dwDomainId, BOOL fWaitUntilDone) return UnloadAppDomain2(dwDomainId, fWaitUntilDone, nullptr); } +void DumpTypeLoadTimingInfo(); +void DumpAssemblyLoadTimingInfo(); +void FlushTimingInfo(); + STDMETHODIMP CorHost2::UnloadAppDomain2(DWORD dwDomainId, BOOL fWaitUntilDone, int *pLatchedExitCode) { WRAPPER_NO_CONTRACT; @@ -872,6 +876,10 @@ STDMETHODIMP CorHost2::UnloadAppDomain2(DWORD dwDomainId, BOOL fWaitUntilDone, i if (1 == refCount) { // Stop coreclr on unload. + DumpTypeLoadTimingInfo(); + DumpAssemblyLoadTimingInfo(); + FlushTimingInfo(); + EEShutDown(FALSE); } else diff --git a/src/coreclr/vm/methodtablebuilder.cpp b/src/coreclr/vm/methodtablebuilder.cpp index 949040ea47006..0caa76662113e 100644 --- a/src/coreclr/vm/methodtablebuilder.cpp +++ b/src/coreclr/vm/methodtablebuilder.cpp @@ -12247,6 +12247,140 @@ BOOL HasLayoutMetadata(Assembly* pAssembly, IMDInternalImport* pInternalImport, return TRUE; } +static int64_t TypeLoadCallCount = 0; +static int64_t TypeLoadTickCount = 0; + +struct TypeLoadTiming +{ + int64_t Ticks; + TypeHandle Type; +}; + +const int RING_BUFFER_SIZE = 65536; + +static TypeLoadTiming TypeLoadTimingRingBuffer[RING_BUFFER_SIZE]; +static volatile long TypeLoadRingBufferIndex = 0; +static volatile HANDLE LogFileHandle = INVALID_HANDLE_VALUE; +static volatile int64_t TimerFrequency = 0; + +int64_t GetPreciseTickCount() +{ + int64_t result; + QueryPerformanceCounter((LARGE_INTEGER *)&result); + return result; +} + +void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks) +{ + InterlockedAdd64(&TypeLoadTickCount, ticks); + InterlockedIncrement64(&TypeLoadCallCount); + long timingIndex = InterlockedIncrement(&TypeLoadRingBufferIndex) - 1; + if (timingIndex >= 0 && timingIndex < RING_BUFFER_SIZE) + { + TypeLoadTimingRingBuffer[timingIndex].Ticks = ticks; + TypeLoadTimingRingBuffer[timingIndex].Type = type; + } +} + +void DumpTimingInfo(const char *action, int64_t callCount, int64_t tickCount) +{ +#if !defined(DACCESS_COMPILE) + static Crst lock(CrstPEImage); + + CrstHolder holder(&lock); + + static long timingCallCount = 0; + static char buffer[1024]; + + if (LogFileHandle == INVALID_HANDLE_VALUE) + { + QueryPerformanceFrequency((LARGE_INTEGER *)&TimerFrequency); + + LogFileHandle = CreateFileA("c:\\triage\\functions\\timing-info.txt", + GENERIC_READ | GENERIC_WRITE, + 0, + NULL, + CREATE_ALWAYS, + FILE_ATTRIBUTE_NORMAL, + NULL); + + const char *titleLine = "CALLS/INDEX | TICKS | SECS | ACTION\n"; + WriteFile(LogFileHandle, titleLine, (DWORD)strlen(titleLine), nullptr, nullptr); + fputs(titleLine, stdout); + } + + snprintf(buffer, sizeof(buffer), "%11lld | %10lld | %12.9f | %s\n", callCount, tickCount, tickCount / (double)TimerFrequency, action); + fputs(buffer, stdout); + WriteFile(LogFileHandle, buffer, (DWORD)strlen(buffer), nullptr, nullptr); +#endif +} + +void FlushTimingInfo() +{ + if (LogFileHandle != INVALID_HANDLE_VALUE) + { + FlushFileBuffers(LogFileHandle); + CloseHandle(LogFileHandle); + LogFileHandle = INVALID_HANDLE_VALUE; + } +} + +static const int TypeNameBufferSize = 65536; +static char TypeNameBuffer[TypeNameBufferSize]; + +char *FormatTypeName(char *typeBuffer, TypeHandle type) +{ + if (type.IsTypeDesc()) + { + SString buffer; + type.AsTypeDesc()->GetName(buffer); + strcpy(typeBuffer, buffer.GetUTF8()); + typeBuffer += strlen(typeBuffer); + return typeBuffer; + } + + MethodTable *pMT = type.AsMethodTable(); + { + SString buffer; + pMT->_GetFullyQualifiedNameForClassNestedAware(buffer); + strcpy(typeBuffer, buffer.GetUTF8()); + } + typeBuffer += strlen(typeBuffer); + + Instantiation instantiation = pMT->GetInstantiation(); + if (!instantiation.IsEmpty()) + { + for (DWORD argIndex = 0; argIndex < instantiation.GetNumArgs(); argIndex++) + { + strcpy(typeBuffer, argIndex == 0 ? "<" : ", "); + typeBuffer += strlen(typeBuffer); + typeBuffer = FormatTypeName(typeBuffer, instantiation[argIndex]); + } + *typeBuffer++ = '>'; + *typeBuffer = 0; + } + return typeBuffer; +} + +void DumpTypeLoadTimingInfo() +{ + + for (int32_t ringBufferIndex = 0; ringBufferIndex < TypeLoadRingBufferIndex; ringBufferIndex++) + { + TypeLoadTiming& timing = TypeLoadTimingRingBuffer[ringBufferIndex]; + char *typeBuffer = FormatTypeName(TypeNameBuffer, timing.Type); + + if (typeBuffer >= TypeNameBuffer + TypeNameBufferSize) + { + CrashDumpAndTerminateProcess(STATUS_STACK_BUFFER_OVERRUN); + } + + DumpTimingInfo(TypeNameBuffer, ringBufferIndex, timing.Ticks); + } + + DumpTimingInfo("LoadTypeHandleForTypeKey", TypeLoadCallCount, TypeLoadTickCount); +} + //--------------------------------------------------------------------------------------- // // This service is called for normal classes -- and for the pseudo class we invent to @@ -12260,6 +12394,8 @@ ClassLoader::CreateTypeHandleForTypeDefThrowing( Instantiation inst, AllocMemTracker * pamTracker) { + int64_t startTicks = GetPreciseTickCount(); + CONTRACT(TypeHandle) { STANDARD_VM_CHECK; From 7ba75c6e878ef667664775f9a3538c64210de640 Mon Sep 17 00:00:00 2001 From: Tomas Rylek Date: Wed, 22 Nov 2023 23:02:21 +0100 Subject: [PATCH 2/7] Add support for logging thread IDs and per-thread type load summary --- src/coreclr/vm/appdomain.cpp | 4 +- src/coreclr/vm/methodtablebuilder.cpp | 57 ++++++++++++++++++++++----- 2 files changed, 50 insertions(+), 11 deletions(-) diff --git a/src/coreclr/vm/appdomain.cpp b/src/coreclr/vm/appdomain.cpp index eaff46eb002b5..0b84324f2f111 100644 --- a/src/coreclr/vm/appdomain.cpp +++ b/src/coreclr/vm/appdomain.cpp @@ -2563,12 +2563,12 @@ static int64_t AssemblyLoadCallCount = 0; static int64_t AssemblyLoadTickCount = 0; int64_t GetPreciseTickCount(); -void DumpTimingInfo(const char *action, int64_t callCount, int64_t tickCount); +void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount); void DumpAssemblyLoadTimingInfo() { #ifndef DACCESS_COMPILE - DumpTimingInfo("AppDomain::LoadDomainAssembly", AssemblyLoadCallCount, AssemblyLoadTickCount); + DumpTimingInfo("AppDomain::LoadDomainAssembly", GetCurrentThreadId(), AssemblyLoadCallCount, AssemblyLoadTickCount); #endif } diff --git a/src/coreclr/vm/methodtablebuilder.cpp b/src/coreclr/vm/methodtablebuilder.cpp index 0caa76662113e..dfdc4a49f078d 100644 --- a/src/coreclr/vm/methodtablebuilder.cpp +++ b/src/coreclr/vm/methodtablebuilder.cpp @@ -12252,6 +12252,7 @@ static int64_t TypeLoadTickCount = 0; struct TypeLoadTiming { + uint32_t Thread; int64_t Ticks; TypeHandle Type; }; @@ -12277,12 +12278,13 @@ void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks) long timingIndex = InterlockedIncrement(&TypeLoadRingBufferIndex) - 1; if (timingIndex >= 0 && timingIndex < RING_BUFFER_SIZE) { + TypeLoadTimingRingBuffer[timingIndex].Thread = GetCurrentThreadId(); TypeLoadTimingRingBuffer[timingIndex].Ticks = ticks; TypeLoadTimingRingBuffer[timingIndex].Type = type; } } -void DumpTimingInfo(const char *action, int64_t callCount, int64_t tickCount) +void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount) { #if !defined(DACCESS_COMPILE) static Crst lock(CrstPEImage); @@ -12290,13 +12292,25 @@ void DumpTimingInfo(const char *action, int64_t callCount, int64_t tickCount) CrstHolder holder(&lock); static long timingCallCount = 0; - static char buffer[1024]; + static const int BufferSize = 1024; + static char buffer[BufferSize]; + static const char *TimingInfoFileName = +#ifdef TARGET_WINDOWS + "\\" +#else + "/" +#endif + "timing-info.txt"; if (LogFileHandle == INVALID_HANDLE_VALUE) { QueryPerformanceFrequency((LARGE_INTEGER *)&TimerFrequency); - - LogFileHandle = CreateFileA("c:\\triage\\functions\\timing-info.txt", + GetCurrentDirectoryA(BufferSize, buffer); + strcat_s(buffer, BufferSize, TimingInfoFileName); + fputs("Output file: ", stdout); + puts(buffer); + + LogFileHandle = CreateFileA(buffer, GENERIC_READ | GENERIC_WRITE, 0, NULL, @@ -12304,12 +12318,12 @@ void DumpTimingInfo(const char *action, int64_t callCount, int64_t tickCount) FILE_ATTRIBUTE_NORMAL, NULL); - const char *titleLine = "CALLS/INDEX | TICKS | SECS | ACTION\n"; + const char *titleLine = "CALLS/INDEX | THREAD | SECS | ACTION\n"; WriteFile(LogFileHandle, titleLine, (DWORD)strlen(titleLine), nullptr, nullptr); fputs(titleLine, stdout); } - snprintf(buffer, sizeof(buffer), "%11lld | %10lld | %12.9f | %s\n", callCount, tickCount, tickCount / (double)TimerFrequency, action); + snprintf(buffer, sizeof(buffer), "%11lld | %8x | %12.9f | %s\n", callCount, threadID, tickCount / (double)TimerFrequency, action); fputs(buffer, stdout); WriteFile(LogFileHandle, buffer, (DWORD)strlen(buffer), nullptr, nullptr); #endif @@ -12364,10 +12378,12 @@ char *FormatTypeName(char *typeBuffer, TypeHandle type) void DumpTypeLoadTimingInfo() { + HashMap threadMap; + threadMap.Init(/*cbInitialSize*/ 32, /*fAsyncMode*/ false, /*pLock*/ nullptr); for (int32_t ringBufferIndex = 0; ringBufferIndex < TypeLoadRingBufferIndex; ringBufferIndex++) { - TypeLoadTiming& timing = TypeLoadTimingRingBuffer[ringBufferIndex]; + const TypeLoadTiming& timing = TypeLoadTimingRingBuffer[ringBufferIndex]; char *typeBuffer = FormatTypeName(TypeNameBuffer, timing.Type); if (typeBuffer >= TypeNameBuffer + TypeNameBufferSize) @@ -12375,10 +12391,33 @@ void DumpTypeLoadTimingInfo() CrashDumpAndTerminateProcess(STATUS_STACK_BUFFER_OVERRUN); } - DumpTimingInfo(TypeNameBuffer, ringBufferIndex, timing.Ticks); + DumpTimingInfo(TypeNameBuffer, timing.Thread, ringBufferIndex, timing.Ticks); + if (threadMap.LookupValue(timing.Thread, timing.Thread) == INVALIDENTRY) + { + threadMap.InsertValue(timing.Thread, timing.Thread); + } + } + + for (HashMap::Iterator it = threadMap.begin(); !it.end(); ++it) + { + uint32_t threadID = (uint32_t)it.GetKey(); + int32_t sumCount = 0; + int64_t sumTicks = 0; + for (int32_t ringBufferIndex = 0; ringBufferIndex < TypeLoadRingBufferIndex; ringBufferIndex++) + { + const TypeLoadTiming& timing = TypeLoadTimingRingBuffer[ringBufferIndex]; + if (timing.Thread == threadID) + { + sumTicks += timing.Ticks; + sumCount++; + } + } + char buffer[100]; + sprintf(buffer, "LoadTypeHandleForTypeKey @ %08x", threadID); + DumpTimingInfo(buffer, threadID, sumCount, sumTicks); } - DumpTimingInfo("LoadTypeHandleForTypeKey", TypeLoadCallCount, TypeLoadTickCount); + DumpTimingInfo("LoadTypeHandleForTypeKey", GetCurrentThreadId(), TypeLoadCallCount, TypeLoadTickCount); } //--------------------------------------------------------------------------------------- From 5a9eb4c8e7072fe3eff728913c228e7c9e363aed Mon Sep 17 00:00:00 2001 From: Tomas Rylek Date: Fri, 24 Nov 2023 17:29:26 +0100 Subject: [PATCH 3/7] Metadata instrumentation --- src/coreclr/md/inc/metamodelro.h | 54 +++++++++ src/coreclr/md/runtime/mdinternalro.cpp | 154 ++++++++++++++++++++++++ src/coreclr/md/runtime/metamodelro.cpp | 120 ++++++++++++++++++ src/coreclr/vm/corhost.cpp | 2 + src/coreclr/vm/methodtablebuilder.cpp | 67 +---------- 5 files changed, 333 insertions(+), 64 deletions(-) diff --git a/src/coreclr/md/inc/metamodelro.h b/src/coreclr/md/inc/metamodelro.h index de229263cbdce..7cd6499711e8f 100644 --- a/src/coreclr/md/inc/metamodelro.h +++ b/src/coreclr/md/inc/metamodelro.h @@ -20,6 +20,60 @@ #include "../heaps/export.h" #include "../tables/export.h" +int64_t GetPreciseTickCount(); + +class MDInstrumentedMethod +{ +public: + class Execution + { + private: + MDInstrumentedMethod *_instrumentedMethod; + int64_t _startTicks; + + public: + Execution(MDInstrumentedMethod *method) + : _instrumentedMethod(method) + { +#ifndef DACCESS_COMPILE + _startTicks = GetPreciseTickCount(); +#endif + } + + ~Execution() + { +#ifndef DACCESS_COMPILE + _instrumentedMethod->Add(GetPreciseTickCount() - _startTicks); +#endif + } + }; + +private: + static MDInstrumentedMethod *s_list; + + const char *_methodName; + int64_t _count; + int64_t _ticks; + MDInstrumentedMethod *_next; + +public: + MDInstrumentedMethod(const char *methodName); + + static void DumpAllTiming(); + void Add(int64_t ticks); + +private: + void DumpTiming(); +}; + +#ifdef MD_INSTRUMENTATION +#define MD_INSTRUMENTED_METHOD(name) \ + static MDInstrumentedMethod s_instrumentedMethod(name); \ + MDInstrumentedMethod::Execution methodExecution(&s_instrumentedMethod); +#else +#define MD_INSTRUMENTED_METHOD(name) +#endif + //***************************************************************************** // A read-only MiniMd. This is the fastest and smallest possible MiniMd, // and as such, is the preferred EE metadata provider. diff --git a/src/coreclr/md/runtime/mdinternalro.cpp b/src/coreclr/md/runtime/mdinternalro.cpp index 96d7255848552..6cf4d3390c2e3 100644 --- a/src/coreclr/md/runtime/mdinternalro.cpp +++ b/src/coreclr/md/runtime/mdinternalro.cpp @@ -96,6 +96,8 @@ ULONG MDInternalRO::Release() __checkReturn HRESULT MDInternalRO::QueryInterface(REFIID riid, void **ppUnk) { + MD_INSTRUMENTED_METHOD("MDInternalRO::QueryInterface") + *ppUnk = 0; if (riid == IID_IUnknown) @@ -119,6 +121,8 @@ HRESULT MDInternalRO::Init( LPVOID pData, // points to meta data section in memory ULONG cbData) // count of bytes in pData { + MD_INSTRUMENTED_METHOD("MDInternalRO::Init"); + m_tdModule = COR_GLOBAL_PARENT_TOKEN; extern HRESULT _CallInitOnMemHelper(CLiteWeightStgdb *pStgdb, ULONG cbData, LPCVOID pData); @@ -142,6 +146,8 @@ HRESULT MDInternalRO::TranslateSigWithScope( CQuickBytes* pqkSigEmit, // [OUT] buffer to hold translated signature ULONG* pcbSig) // [OUT] count of bytes in the translated signature { + MD_INSTRUMENTED_METHOD("MDInternalRO::TranslateSigWithScope"); + return TranslateSigHelper( this, pAssemImport, @@ -161,6 +167,8 @@ HRESULT MDInternalRO::GetTypeDefRefTokenInTypeSpec(// return S_FALSE if enclosin mdTypeSpec tkTypeSpec, // [IN] TypeSpec token to look at mdToken *tkEnclosedToken) // [OUT] The enclosed type token { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetTypeDefRefTokenInTypeSpec"); + return m_LiteWeightStgdb.m_MiniMd.GetTypeDefRefTokenInTypeSpec(tkTypeSpec, tkEnclosedToken); } // MDInternalRO::GetTypeDefRefTokenInTypeSpec @@ -171,6 +179,8 @@ HRESULT MDInternalRO::GetTypeDefRefTokenInTypeSpec(// return S_FALSE if enclosin ULONG MDInternalRO::GetCountWithTokenKind( // return hresult DWORD tkKind) // [IN] pass in the kind of token. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetCountWithTokenKind"); + ULONG ulCount = m_LiteWeightStgdb.m_MiniMd.CommonGetRowCount(tkKind); if (tkKind == mdtTypeDef) { @@ -194,6 +204,8 @@ __checkReturn HRESULT MDInternalRO::EnumTypeDefInit( // return hresult HENUMInternal *phEnum) // [OUT] buffer to fill for enumerator data { + MD_INSTRUMENTED_METHOD("MDInternalRO::EnumTypeDefInit"); + HRESULT hr = NOERROR; _ASSERTE(phEnum); @@ -226,6 +238,8 @@ HRESULT MDInternalRO::EnumMethodImplInit( // return hresult HENUMInternal *phEnumBody, // [OUT] buffer to fill for enumerator data for MethodBody tokens. HENUMInternal *phEnumDecl) // [OUT] buffer to fill for enumerator data for MethodDecl tokens. { + MD_INSTRUMENTED_METHOD("MDInternalRO::EnumMethodImplInit"); + return EnumInit(TBL_MethodImpl << 24, td, phEnumBody); } // MDInternalRO::EnumMethodImplInit @@ -252,6 +266,8 @@ MDInternalRO::EnumMethodImplNext( // return hresult mdToken *ptkBody, // [OUT] return token for MethodBody mdToken *ptkDecl) // [OUT] return token for MethodDecl { + MD_INSTRUMENTED_METHOD("MDInternalRO::EnumMethodImplNext"); + HRESULT hr; MethodImplRec *pRecord; @@ -328,6 +344,8 @@ HRESULT MDInternalRO::EnumInit( // return S_FALSE if record not found mdToken tkParent, // [IN] token to scope the search HENUMInternal *phEnum) // [OUT] the enumerator to fill { + MD_INSTRUMENTED_METHOD("MDInternalRO::EnumInit"); + HRESULT hr = S_OK; ULONG ulMax = 0; @@ -497,6 +515,8 @@ HRESULT MDInternalRO::EnumAllInit( // return S_FALSE if record not found DWORD tkKind, // [IN] which table to work on HENUMInternal *phEnum) // [OUT] the enumerator to fill { + MD_INSTRUMENTED_METHOD("MDInternalRO::EnumAllInit"); + HRESULT hr = S_OK; // Vars for query. @@ -577,6 +597,8 @@ HRESULT MDInternalRO::EnumCustomAttributeByNameInit(// return S_FALSE if record LPCSTR szName, // [IN] CustomAttribute's name to scope the search HENUMInternal *phEnum) // [OUT] the enumerator to fill { + MD_INSTRUMENTED_METHOD("MDInternalRO::EnumCustomAttributeByNameInit"); + return m_LiteWeightStgdb.m_MiniMd.CommonEnumCustomAttributeByName(tkParent, szName, false, phEnum); } // MDInternalRO::EnumCustomAttributeByNameInit @@ -599,6 +621,8 @@ HRESULT MDInternalRO::GetParentToken( mdToken tkChild, // [IN] given child token mdToken *ptkParent) // [OUT] returning parent { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetParentToken"); + HRESULT hr = NOERROR; _ASSERTE(ptkParent); @@ -679,6 +703,8 @@ MDInternalRO::GetCustomAttributeProps( // S_OK or error. mdCustomAttribute at, // The attribute. mdToken *ptkType) // Put attribute type here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetCustomAttributeProps"); + HRESULT hr; _ASSERTE(TypeFromToken(at) == mdtCustomAttribute); @@ -702,6 +728,8 @@ MDInternalRO::GetCustomAttributeAsBlob( void const **ppBlob, // [OUT] return the pointer to internal blob ULONG *pcbSize) // [OUT] return the size of the blob { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetCustomAttributeAsBlob"); + HRESULT hr; _ASSERTE(ppBlob && pcbSize && TypeFromToken(cv) == mdtCustomAttribute); @@ -723,6 +751,8 @@ HRESULT MDInternalRO::GetCustomAttributeByName( // S_OK or error. _Outptr_result_bytebuffer_(*pcbData) const void **ppData, // [OUT] Put pointer to data here. _Out_ ULONG *pcbData) // [OUT] Put size of data here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetCustomAttributeByName"); + return m_LiteWeightStgdb.m_MiniMd.CommonGetCustomAttributeByNameEx(tkObj, szName, NULL, ppData, pcbData); } // MDInternalRO::GetCustomAttributeByName @@ -736,6 +766,8 @@ HRESULT MDInternalRO::GetNameOfCustomAttribute( // S_OK or error. LPCUTF8 *pszNamespace, // [OUT] Namespace of Custom Attribute. LPCUTF8 *pszName) // [OUT] Name of Custom Attribute. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfCustomAttribute"); + _ASSERTE(TypeFromToken(mdAttribute) == mdtCustomAttribute); HRESULT hr = m_LiteWeightStgdb.m_MiniMd.CommonGetNameOfCustomAttribute(RidFromToken(mdAttribute), pszNamespace, pszName); @@ -751,6 +783,8 @@ MDInternalRO::GetScopeProps( LPCSTR *pszName, // [OUT] scope name GUID *pmvid) // [OUT] version id { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetScopeProps"); + HRESULT hr; ModuleRec *pModuleRec; @@ -798,6 +832,7 @@ HRESULT MDInternalRO::FindMethodDef( // S_OK or error. ULONG cbSigBlob, // [IN] count of bytes in the signature blob mdMethodDef *pmethoddef) // Put MemberDef token here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindMethodDef"); return FindMethodDefUsingCompare(classdef, szName, @@ -821,6 +856,8 @@ HRESULT MDInternalRO::FindMethodDefUsingCompare( // S_OK or error. void* pSigArgs, // [IN] Additional arguments passed to signature compare mdMethodDef *pmethoddef) // Put MemberDef token here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindMethodDefUsingCompare"); + HRESULT hr = NOERROR; PCCOR_SIGNATURE pvSigTemp = pvSigBlob; CQuickBytes qbSig; @@ -897,6 +934,8 @@ HRESULT MDInternalRO::FindParamOfMethod(// S_OK or error. ULONG iSeq, // [IN] The sequence # of the param. mdParamDef *pparamdef) // [OUT] Put ParamDef token here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindParamOfMethod"); + HRESULT hr; ParamRec *pParamRec; RID ridStart, ridEnd; @@ -945,6 +984,8 @@ MDInternalRO::GetNameOfTypeDef( // return hresult LPCSTR* pszname, // pointer to an internal UTF8 string LPCSTR* psznamespace) // pointer to the namespace. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfTypeDef"); + HRESULT hr; if (pszname != NULL) @@ -983,6 +1024,8 @@ HRESULT MDInternalRO::GetIsDualOfTypeDef(// return hresult mdTypeDef classdef, // given classdef ULONG *pDual) // [OUT] return dual flag here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetIsDualOfTypeDef"); + ULONG iFace=0; // Iface type. HRESULT hr; // A result. @@ -1000,6 +1043,8 @@ HRESULT MDInternalRO::GetIfaceTypeOfTypeDef( mdTypeDef classdef, // [IN] given classdef. ULONG *pIface) // [OUT] 0=dual, 1=vtable, 2=dispinterface { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetIfaceTypeOfTypeDef"); + HRESULT hr; // A result. const BYTE *pVal; // The custom value. ULONG cbVal; // Size of the custom value. @@ -1035,6 +1080,8 @@ MDInternalRO::GetNameOfMethodDef( mdMethodDef md, LPCSTR *pszMethodName) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfMethodDef"); + HRESULT hr; MethodRec *pMethodRec; *pszMethodName = NULL; @@ -1054,6 +1101,8 @@ MDInternalRO::GetNameAndSigOfMethodDef( ULONG *pcbSigBlob, // [OUT] count of bytes in the signature blob LPCSTR *pszMethodName) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameAndSigOfMethodDef"); + HRESULT hr; // Output parameter should not be NULL _ASSERTE(ppvSigBlob && pcbSigBlob); @@ -1078,6 +1127,8 @@ MDInternalRO::GetNameOfFieldDef( // return hresult mdFieldDef fd, // given field LPCSTR *pszFieldName) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfFieldDef"); + HRESULT hr; FieldRec *pFieldRec; *pszFieldName = NULL; @@ -1098,6 +1149,8 @@ MDInternalRO::GetNameOfTypeRef( // return TypeDef's name LPCSTR *pszname) // [OUT] return typeref namespace { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfTypeRef"); + _ASSERTE(TypeFromToken(classref) == mdtTypeRef); HRESULT hr; @@ -1121,6 +1174,8 @@ MDInternalRO::GetResolutionScopeOfTypeRef( mdTypeRef classref, // given classref mdToken *ptkResolutionScope) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetResolutionScopeOfTypeRef"); + _ASSERTE(TypeFromToken(classref) == mdtTypeRef && RidFromToken(classref)); HRESULT hr; @@ -1142,6 +1197,8 @@ HRESULT MDInternalRO::FindTypeRefByName( // S_OK or error. mdToken tkResolutionScope, // [IN] Resolution Scope fo the TypeRef. mdTypeRef *ptk) // [OUT] TypeRef token returned. { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindTypeRefByName"); + HRESULT hr = NOERROR; _ASSERTE(ptk); @@ -1202,6 +1259,8 @@ HRESULT MDInternalRO::GetTypeDefProps( DWORD *pdwAttr, // return flags on class mdToken *ptkExtends) // [OUT] Put base class TypeDef/TypeRef here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetTypeDefProps"); + HRESULT hr; TypeDefRec *pTypeDefRec; IfFailRet(m_LiteWeightStgdb.m_MiniMd.GetTypeDefRecord(RidFromToken(td), &pTypeDefRec)); @@ -1227,6 +1286,7 @@ HRESULT MDInternalRO::GetItemGuid( // return hresult mdToken tkObj, // given item CLSID *pGuid) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetItemGuid"); HRESULT hr; // A result. const BYTE *pBlob = NULL; // Blob with dispid. @@ -1266,6 +1326,8 @@ HRESULT MDInternalRO::GetNestedClassProps( // S_OK or error mdTypeDef tkNestedClass, // [IN] NestedClass token. mdTypeDef *ptkEnclosingClass) // [OUT] EnclosingClass token. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNestedClassProps"); + HRESULT hr; _ASSERTE(TypeFromToken(tkNestedClass) == mdtTypeDef && ptkEnclosingClass); @@ -1294,6 +1356,8 @@ MDInternalRO::GetCountNestedClasses( // return count of Nested classes. mdTypeDef tkEnclosingClass, // [IN]Enclosing class. ULONG *pcNestedClassesCount) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetCountNestedClasses"); + HRESULT hr; ULONG ulCount; ULONG ulRetCount = 0; @@ -1326,6 +1390,8 @@ MDInternalRO::GetNestedClasses( // Return actual count. ULONG ulNestedClasses, // [IN] Size of array. ULONG *pcNestedClasses) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNestedClasses"); + HRESULT hr; ULONG ulCount; ULONG ulRetCount = 0; @@ -1360,6 +1426,8 @@ HRESULT MDInternalRO::GetModuleRefProps( // return hresult mdModuleRef mur, // [IN] moduleref token LPCSTR *pszName) // [OUT] buffer to fill with the moduleref name { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetModuleRefProps"); + _ASSERTE(TypeFromToken(mur) == mdtModuleRef); _ASSERTE(pszName); @@ -1391,6 +1459,8 @@ MDInternalRO::GetSigOfMethodDef( ULONG *pcbSigBlob, // [OUT] count of bytes in the signature blob PCCOR_SIGNATURE *ppSig) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetSigOfMethodDef"); + // Output parameter should not be NULL _ASSERTE(pcbSigBlob); _ASSERTE(TypeFromToken(methoddef) == mdtMethodDef); @@ -1415,6 +1485,8 @@ MDInternalRO::GetSigOfFieldDef( ULONG *pcbSigBlob, // [OUT] count of bytes in the signature blob PCCOR_SIGNATURE *ppSig) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetSigOfFieldDef"); + _ASSERTE(pcbSigBlob); _ASSERTE(TypeFromToken(fielddef) == mdtFieldDef); @@ -1437,6 +1509,8 @@ MDInternalRO::GetSigFromToken( ULONG * pcbSig, PCCOR_SIGNATURE * ppSig) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetSigFromToken"); + HRESULT hr; *ppSig = NULL; @@ -1484,6 +1558,8 @@ MDInternalRO::GetMethodDefProps( mdMethodDef md, DWORD *pdwFlags) // return mdPublic, mdAbstract, etc { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetMethodDefProps"); + HRESULT hr; MethodRec *pMethodRec; @@ -1503,6 +1579,8 @@ HRESULT MDInternalRO::GetMethodImplProps( ULONG *pulCodeRVA, // [OUT] CodeRVA DWORD *pdwImplFlags) // [OUT] Impl. Flags { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetMethodImplProps"); + HRESULT hr; _ASSERTE(TypeFromToken(tk) == mdtMethodDef); @@ -1531,6 +1609,8 @@ HRESULT MDInternalRO::GetFieldRVA( mdToken fd, // [IN] FieldDef ULONG *pulCodeRVA) // [OUT] CodeRVA { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetFieldRVA"); + HRESULT hr; _ASSERTE(TypeFromToken(fd) == mdtFieldDef); _ASSERTE(pulCodeRVA); @@ -1561,6 +1641,8 @@ MDInternalRO::GetFieldDefProps( mdFieldDef fd, // given memberdef DWORD *pdwFlags) // [OUT] return fdPublic, fdPrive, etc flags { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetFieldDefProps"); + HRESULT hr; _ASSERTE(TypeFromToken(fd) == mdtFieldDef); @@ -1581,6 +1663,8 @@ HRESULT MDInternalRO::GetDefaultValue( // return hresult mdToken tk, // [IN] given FieldDef, ParamDef, or Property MDDefaultValue *pMDDefaultValue) // [OUT] default value { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetDefaultValue"); + _ASSERTE(pMDDefaultValue); HRESULT hr; @@ -1615,6 +1699,8 @@ HRESULT MDInternalRO::GetDispIdOfMemberDef( // return hresult mdToken tk, // given methoddef or fielddef ULONG *pDispid) // Put the dispid here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetDispIdOfMemberDef"); + #ifdef FEATURE_COMINTEROP HRESULT hr; // A result. const BYTE *pBlob; // Blob with dispid. @@ -1651,6 +1737,8 @@ MDInternalRO::GetTypeOfInterfaceImpl( // return hresult mdInterfaceImpl iiImpl, // given a interfaceimpl mdToken *ptkType) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetTypeOfInterfaceImpl"); + HRESULT hr; _ASSERTE(TypeFromToken(iiImpl) == mdtInterfaceImpl); @@ -1672,6 +1760,8 @@ HRESULT MDInternalRO::GetMethodSpecProps( // S_OK or error. PCCOR_SIGNATURE *ppvSigBlob, // [OUT] point to the blob value of meta data ULONG *pcbSigBlob) // [OUT] actual size of signature blob { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetMethodSpecProps"); + HRESULT hr = NOERROR; MethodSpecRec *pMethodSpecRec; @@ -1711,6 +1801,8 @@ MDInternalRO::FindTypeDef( mdToken tkEnclosingClass, // [IN] TypeDef/TypeRef of enclosing class. mdTypeDef * ptkTypeDef) // [OUT] return typedef { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindTypeDef"); + HRESULT hr = S_OK; _ASSERTE((szTypeDefName != NULL) && (ptkTypeDef != NULL)); @@ -1816,6 +1908,8 @@ MDInternalRO::GetNameAndSigOfMemberRef( // meberref's name ULONG *pcbSigBlob, // [OUT] count of bytes in the signature blob LPCSTR *pszMemberRefName) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameAndSigOfMemberRef"); + _ASSERTE(TypeFromToken(memberref) == mdtMemberRef); HRESULT hr; @@ -1845,6 +1939,8 @@ MDInternalRO::GetParentOfMemberRef( mdMemberRef memberref, // given a typedef mdToken *ptkParent) // return the parent token { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetParentOfMemberRef"); + HRESULT hr; _ASSERTE(TypeFromToken(memberref) == mdtMemberRef); @@ -1868,6 +1964,8 @@ MDInternalRO::GetParamDefProps ( DWORD *pdwAttr, // [OUT] flags LPCSTR *pszName) // [OUT] return the name of the parameter { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetParamDefProps"); + _ASSERTE(TypeFromToken(paramdef) == mdtParamDef); HRESULT hr; ParamRec *pParamRec; @@ -1920,6 +2018,8 @@ HRESULT MDInternalRO::GetPropertyInfoForMethodDef( // Result. LPCSTR *pName, // [OUT] put pointer to name here ULONG *pSemantic) // [OUT] put semantic here { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetPropertyInfoForMethodDef"); + HRESULT hr; MethodSemanticsRec *pSemantics; // A MethodSemantics record. MethodSemanticsRec *pFound=0; // A MethodSemantics record that is a property for the desired function. @@ -2077,6 +2177,8 @@ HRESULT MDInternalRO::GetClassPackSize( mdTypeDef td, // [IN] give typedef DWORD *pdwPackSize) // [OUT] { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetClassPackSize"); + HRESULT hr = NOERROR; _ASSERTE(TypeFromToken(td) == mdtTypeDef && pdwPackSize); @@ -2106,6 +2208,8 @@ HRESULT MDInternalRO::GetClassTotalSize( // return error if a class does not hav mdTypeDef td, // [IN] give typedef ULONG *pulClassSize) // [OUT] return the total size of the class { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetClassTotalSize"); + _ASSERTE(TypeFromToken(td) == mdtTypeDef && pulClassSize); ClassLayoutRec *pRec; @@ -2134,6 +2238,8 @@ HRESULT MDInternalRO::GetClassLayoutInit( mdTypeDef td, // [IN] give typedef MD_CLASS_LAYOUT *pmdLayout) // [OUT] set up the status of query here { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetClassLayoutInit"); + HRESULT hr = NOERROR; _ASSERTE(TypeFromToken(td) == mdtTypeDef); @@ -2161,6 +2267,8 @@ HRESULT MDInternalRO::GetFieldOffset( mdFieldDef fd, // [IN] fielddef ULONG *pulOffset) // [OUT] FieldOffset { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetFieldOffset"); + HRESULT hr = S_OK; FieldLayoutRec *pRec; @@ -2194,6 +2302,8 @@ HRESULT MDInternalRO::GetClassLayoutNext( mdFieldDef *pfd, // [OUT] field def ULONG *pulOffset) // [OUT] field offset or sequence { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetClassLayoutNext"); + HRESULT hr = S_OK; _ASSERTE(pfd && pulOffset && pLayout); @@ -2236,6 +2346,8 @@ HRESULT MDInternalRO::GetFieldMarshal( // return error if no native type associ PCCOR_SIGNATURE *pSigNativeType, // [OUT] the native type signature ULONG *pcbNativeType) // [OUT] the count of bytes of *ppvNativeType { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetFieldMarshal"); + // output parameters have to be supplied _ASSERTE(pcbNativeType); @@ -2275,6 +2387,8 @@ HRESULT MDInternalRO::FindProperty( LPCSTR szPropName, // [IN] property name mdProperty *pProp) // [OUT] return property token { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindProperty"); + HRESULT hr = NOERROR; // output parameters have to be supplied @@ -2333,6 +2447,8 @@ HRESULT MDInternalRO::GetPropertyProps( PCCOR_SIGNATURE *ppvSig, // [OUT] property type. pointing to meta data internal blob ULONG *pcbSig) // [OUT] count of bytes in *ppvSig { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetPropertyProps"); + // output parameters have to be supplied _ASSERTE(TypeFromToken(prop) == mdtProperty); @@ -2382,6 +2498,8 @@ HRESULT MDInternalRO::FindEvent( LPCSTR szEventName, // [IN] event name mdEvent *pEvent) // [OUT] return event token { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindEvent"); + HRESULT hr = NOERROR; // output parameters have to be supplied @@ -2436,6 +2554,8 @@ HRESULT MDInternalRO::GetEventProps( // S_OK, S_FALSE, or error. DWORD *pdwEventFlags, // [OUT] Event flags. mdToken *ptkEventType) // [OUT] EventType class { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetEventProps"); + // output parameters have to be supplied _ASSERTE(TypeFromToken(ev) == mdtEvent); @@ -2467,6 +2587,8 @@ HRESULT MDInternalRO::GetGenericParamProps( // S_OK or error. DWORD *reserved, // [OUT] The kind (TypeDef/Ref/Spec, for future use) LPCSTR *szName) // [OUT] The name { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetGenericParamProps"); + HRESULT hr = NOERROR; GenericParamRec * pGenericParamRec = NULL; @@ -2505,6 +2627,8 @@ HRESULT MDInternalRO::GetGenericParamConstraintProps( // S_OK or error. mdGenericParam *ptGenericParam, // [OUT] GenericParam that is constrained mdToken *ptkConstraintType) // [OUT] TypeDef/Ref/Spec constraint { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetGenericParamConstraintProps"); + HRESULT hr = NOERROR; GenericParamConstraintRec *pGPCRec; RID ridRD = RidFromToken(rd); @@ -2575,6 +2699,8 @@ HRESULT MDInternalRO::EnumAssociateInit( mdToken evprop, // [IN] given a property or an event token HENUMInternal *phEnum) // [OUT] cursor to hold the query result { + MD_INSTRUMENTED_METHOD("MDInternalRO::EnumAssociateInit"); + HRESULT hr; _ASSERTE(phEnum); @@ -2604,6 +2730,8 @@ HRESULT MDInternalRO::GetAllAssociates( ASSOCIATE_RECORD *pAssociateRec, // [OUT] struct to fill for output ULONG cAssociateRec) // [IN] size of the buffer { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetAllAssociates"); + _ASSERTE(phEnum && pAssociateRec); HRESULT hr; @@ -2634,6 +2762,8 @@ HRESULT MDInternalRO::GetPermissionSetProps( void const **ppvPermission, // [OUT] permission blob. ULONG *pcbPermission) // [OUT] count of bytes of pvPermission. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetPermissionSetProps"); + HRESULT hr; _ASSERTE(TypeFromToken(pm) == mdtPermission); _ASSERTE(pdwAction && ppvPermission && pcbPermission); @@ -2659,6 +2789,8 @@ MDInternalRO::GetUserString( // Offset into the string blob heap. BOOL *pfIs80Plus, // [OUT] specifies where there are extended characters >= 0x80. LPCWSTR *pwszUserString) { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetUserString"); + HRESULT hr; LPWSTR wszTmp; @@ -2707,6 +2839,8 @@ HRESULT MDInternalRO::GetPinvokeMap( LPCSTR *pszImportName, // [OUT] Import name. mdModuleRef *pmrImportDLL) // [OUT] ModuleRef token for the target DLL. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetPinvokeMap"); + HRESULT hr; ImplMapRec *pRecord; RID iRecord; @@ -2746,6 +2880,8 @@ HRESULT MDInternalRO::GetAssemblyProps( AssemblyMetaDataInternal *pMetaData,// [OUT] Assembly MetaData. DWORD *pdwAssemblyFlags) // [OUT] Flags. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetAssemblyProps"); + HRESULT hr; AssemblyRec *pRecord; @@ -2799,6 +2935,8 @@ HRESULT MDInternalRO::GetAssemblyRefProps( ULONG *pcbHashValue, // [OUT] Count of bytes in the hash blob. DWORD *pdwAssemblyRefFlags) // [OUT] Flags. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetAssemblyRefProps"); + HRESULT hr; AssemblyRefRec *pRecord; @@ -2878,6 +3016,8 @@ HRESULT MDInternalRO::GetExportedTypeProps( mdTypeDef *ptkTypeDef, // [OUT] TypeDef token within the file. DWORD *pdwExportedTypeFlags) // [OUT] Flags. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetExportedTypeProps"); + HRESULT hr; ExportedTypeRec *pRecord; @@ -2913,6 +3053,8 @@ HRESULT MDInternalRO::GetManifestResourceProps( DWORD *pdwOffset, // [OUT] Offset to the beginning of the resource within the file. DWORD *pdwResourceFlags) // [OUT] Flags. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetManifestResourceProps"); + HRESULT hr; ManifestResourceRec *pRecord; @@ -2943,6 +3085,8 @@ STDMETHODIMP MDInternalRO::FindExportedTypeByName( // S_OK or error mdExportedType tkEnclosingType, // [IN] Token for the Enclosing Type. mdExportedType *pmct) // [OUT] Put ExportedType token here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindExportedTypeByName"); + IMetaModelCommon *pCommon = static_cast(&m_LiteWeightStgdb.m_MiniMd); return pCommon->CommonFindExportedType(szNamespace, szName, tkEnclosingType, pmct); } // MDInternalRO::FindExportedTypeByName @@ -2955,6 +3099,8 @@ STDMETHODIMP MDInternalRO::FindManifestResourceByName( // S_OK or error LPCSTR szName, // [IN] Name of the resource. mdManifestResource *pmmr) // [OUT] Put ManifestResource token here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::FindManifestResourceByName"); + _ASSERTE(szName && pmmr); HRESULT hr; @@ -2986,6 +3132,8 @@ __checkReturn HRESULT MDInternalRO::GetAssemblyFromScope( // S_OK or error mdAssembly *ptkAssembly) // [OUT] Put token here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetAssemblyFromScope"); + _ASSERTE(ptkAssembly); if (m_LiteWeightStgdb.m_MiniMd.getCountAssemblys()) @@ -3006,6 +3154,8 @@ HRESULT MDInternalRO::GetTypeSpecFromToken( // S_OK or error. PCCOR_SIGNATURE *ppvSig, // [OUT] return pointer to token. ULONG *pcbSig) // [OUT] return size of signature. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetTypeSpecFromToken"); + HRESULT hr = NOERROR; _ASSERTE(TypeFromToken(typespec) == mdtTypeSpec); @@ -3042,6 +3192,8 @@ __checkReturn HRESULT MDInternalRO::GetVersionString( LPCSTR * pVer) // [OUT] Put version string here. { + MD_INSTRUMENTED_METHOD("MDInternalRO::GetVersionString"); + HRESULT hr = NOERROR; if (m_LiteWeightStgdb.m_pvMd != NULL) @@ -3078,6 +3230,8 @@ HRESULT MDInternalRO::ConvertTextSigToComSig(// Return hresult. BOOL MDInternalRO::IsValidToken( // True or False. mdToken tk) // [IN] Given token. { + MD_INSTRUMENTED_METHOD("MDInternalRO::IsValidToken"); + RID rid = RidFromToken(tk); if (rid == 0) { diff --git a/src/coreclr/md/runtime/metamodelro.cpp b/src/coreclr/md/runtime/metamodelro.cpp index 67783a2cf39ea..df4a623be4555 100644 --- a/src/coreclr/md/runtime/metamodelro.cpp +++ b/src/coreclr/md/runtime/metamodelro.cpp @@ -12,6 +12,110 @@ #include #include +static volatile HANDLE LogFileHandle = INVALID_HANDLE_VALUE; +static volatile int64_t TimerFrequency = 0; + +void DumpMetadataTimingInfo() +{ + MDInstrumentedMethod::DumpAllTiming(); +} + +int64_t GetPreciseTickCount() +{ + int64_t result; + QueryPerformanceCounter((LARGE_INTEGER *)&result); + return result; +} + +void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount) +{ + static long timingCallCount = 0; + static const int BufferSize = 1024; + static char buffer[BufferSize]; + static const char *TimingInfoFileName = +#ifdef TARGET_WINDOWS + "\\" +#else + "/" +#endif + "timing-info.txt"; + + if (LogFileHandle == INVALID_HANDLE_VALUE) + { + QueryPerformanceFrequency((LARGE_INTEGER *)&TimerFrequency); + GetCurrentDirectoryA(BufferSize, buffer); + strcat_s(buffer, BufferSize, TimingInfoFileName); + fputs("Output file: ", stdout); + puts(buffer); + + LogFileHandle = CreateFileA(buffer, + GENERIC_READ | GENERIC_WRITE, + 0, + NULL, + CREATE_ALWAYS, + FILE_ATTRIBUTE_NORMAL, + NULL); + + const char *titleLine = "CALLS/INDEX | THREAD | SECS | ACTION\n"; + WriteFile(LogFileHandle, titleLine, (DWORD)strlen(titleLine), nullptr, nullptr); + fputs(titleLine, stdout); + } + + snprintf(buffer, sizeof(buffer), "%11lld | %8x | %12.9f | %s\n", callCount, threadID, tickCount / (double)TimerFrequency, action); + fputs(buffer, stdout); + WriteFile(LogFileHandle, buffer, (DWORD)strlen(buffer), nullptr, nullptr); +} + +void FlushTimingInfo() +{ + if (LogFileHandle != INVALID_HANDLE_VALUE) + { + FlushFileBuffers(LogFileHandle); + CloseHandle(LogFileHandle); + LogFileHandle = INVALID_HANDLE_VALUE; + } +} + +MDInstrumentedMethod *MDInstrumentedMethod::s_list = nullptr; + +MDInstrumentedMethod::MDInstrumentedMethod(const char *methodName) +{ + _methodName = methodName; + _count = 0; + _ticks = 0; + _next = InterlockedExchangeT(&s_list, this); +} + +void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount); + +void MDInstrumentedMethod::DumpAllTiming() +{ + int64_t sumCount = 0; + int64_t sumTicks = 0; + + for (MDInstrumentedMethod *list = s_list; list != nullptr; list = list->_next) + { + list->DumpTiming(); + sumCount += list->_count; + sumTicks += list->_ticks; + } + + DumpTimingInfo("MDInstrumentedMethod", 0, sumCount, sumTicks); +} + +void MDInstrumentedMethod::DumpTiming() +{ +#if !defined(DACCESS_COMPILE) + DumpTimingInfo(_methodName, 0, _count, _ticks); +#endif +} + +void MDInstrumentedMethod::Add(int64_t ticks) +{ + InterlockedIncrement64(&_count); + InterlockedAdd64(&_ticks, ticks); +} + //***************************************************************************** // Set the pointers to consecutive areas of a large buffer. //***************************************************************************** @@ -20,6 +124,8 @@ HRESULT CMiniMd::InitializeTables( MetaData::DataBlob tablesData) { + // MD_INSTRUMENTED_METHOD("CMiniMd::InitializeTables") + HRESULT hr; for (int i = 0; i < TBL_COUNT; i++) @@ -59,6 +165,8 @@ CMiniMd::InitOnMem( void *pvBuf, // The buffer. ULONG ulBufLen) // Size of the buffer.. { + // MD_INSTRUMENTED_METHOD("CMiniMd::InitOnMem") + HRESULT hr = S_OK; ULONG cbData; BYTE *pBuf = reinterpret_cast(pvBuf); @@ -101,6 +209,8 @@ CMiniMd::Impl_GetStringW( ULONG cchBuffer, ULONG *pcchBuffer) { + // MD_INSTRUMENTED_METHOD("CMiniMd::Impl_GetStringW") + LPCSTR szString; // Single byte version. int iSize; // Size of resulting string, in wide chars. HRESULT hr = NOERROR; @@ -161,6 +271,8 @@ CMiniMd::Impl_GetEndRidForColumn( // The End rid. UINT32 nTargetTableIndex, // The other table. RID *pEndRid) { + // MD_INSTRUMENTED_METHOD("CMiniMd::Impl_GetEndRidForColumn") + HRESULT hr; _ASSERTE(nTableIndex < TBL_COUNT); RID nLastRowIndex = m_Schema.m_cRecs[nTableIndex]; @@ -197,6 +309,8 @@ CMiniMd::CommonEnumCustomAttributeByName( bool fStopAtFirstFind, // [IN] just find the first one HENUMInternal *phEnum) // enumerator to fill up { + // MD_INSTRUMENTED_METHOD("CMiniMd::CommonEnumCustomAttributeByName") + HRESULT hr = S_OK; HRESULT hrRet = S_FALSE; // Assume that we won't find any RID ridStart, ridEnd; // Loop start and endpoints. @@ -251,6 +365,8 @@ CMiniMd::vSearchTable( ULONG ulTarget, // Target for search. RID *pRid) // RID of matching row, or 0. { + // MD_INSTRUMENTED_METHOD("CMiniMd::vSearchTable") + HRESULT hr; void *pRow = NULL; // Row from a table. ULONG val; // Value from a row. @@ -296,6 +412,8 @@ CMiniMd::vSearchTableNotGreater( ULONG ulTarget, // target for search RID *pRid) // RID of matching row, or 0 { + // MD_INSTRUMENTED_METHOD("CMiniMd::vSearchTableNotGreater") + HRESULT hr; void *pRow = NULL; // Row from a table. ULONG cRecs; // Rows in the table. @@ -379,6 +497,8 @@ CMiniMd::CommonGetCustomAttributeByNameEx( const void **ppData, // [OUT] Put pointer to data here. ULONG *pcbData) // [OUT] Put size of data here. { + // MD_INSTRUMENTED_METHOD("CMiniMd::CommonGetCustomAttributeByNameEx") + HRESULT hr; ULONG cbData; diff --git a/src/coreclr/vm/corhost.cpp b/src/coreclr/vm/corhost.cpp index e72355369c08d..149b39078d97c 100644 --- a/src/coreclr/vm/corhost.cpp +++ b/src/coreclr/vm/corhost.cpp @@ -839,6 +839,7 @@ STDMETHODIMP CorHost2::UnloadAppDomain(DWORD dwDomainId, BOOL fWaitUntilDone) void DumpTypeLoadTimingInfo(); void DumpAssemblyLoadTimingInfo(); +void DumpMetadataTimingInfo(); void FlushTimingInfo(); STDMETHODIMP CorHost2::UnloadAppDomain2(DWORD dwDomainId, BOOL fWaitUntilDone, int *pLatchedExitCode) @@ -877,6 +878,7 @@ STDMETHODIMP CorHost2::UnloadAppDomain2(DWORD dwDomainId, BOOL fWaitUntilDone, i { // Stop coreclr on unload. DumpTypeLoadTimingInfo(); + DumpMetadataTimingInfo(); DumpAssemblyLoadTimingInfo(); FlushTimingInfo(); diff --git a/src/coreclr/vm/methodtablebuilder.cpp b/src/coreclr/vm/methodtablebuilder.cpp index dfdc4a49f078d..e83c5f2386511 100644 --- a/src/coreclr/vm/methodtablebuilder.cpp +++ b/src/coreclr/vm/methodtablebuilder.cpp @@ -12247,6 +12247,9 @@ BOOL HasLayoutMetadata(Assembly* pAssembly, IMDInternalImport* pInternalImport, return TRUE; } +int64_t GetPreciseTickCount(); +void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount); + static int64_t TypeLoadCallCount = 0; static int64_t TypeLoadTickCount = 0; @@ -12261,15 +12264,6 @@ const int RING_BUFFER_SIZE = 65536; static TypeLoadTiming TypeLoadTimingRingBuffer[RING_BUFFER_SIZE]; static volatile long TypeLoadRingBufferIndex = 0; -static volatile HANDLE LogFileHandle = INVALID_HANDLE_VALUE; -static volatile int64_t TimerFrequency = 0; - -int64_t GetPreciseTickCount() -{ - int64_t result; - QueryPerformanceCounter((LARGE_INTEGER *)&result); - return result; -} void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks) { @@ -12284,61 +12278,6 @@ void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks) } } -void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount) -{ -#if !defined(DACCESS_COMPILE) - static Crst lock(CrstPEImage); - - CrstHolder holder(&lock); - - static long timingCallCount = 0; - static const int BufferSize = 1024; - static char buffer[BufferSize]; - static const char *TimingInfoFileName = -#ifdef TARGET_WINDOWS - "\\" -#else - "/" -#endif - "timing-info.txt"; - - if (LogFileHandle == INVALID_HANDLE_VALUE) - { - QueryPerformanceFrequency((LARGE_INTEGER *)&TimerFrequency); - GetCurrentDirectoryA(BufferSize, buffer); - strcat_s(buffer, BufferSize, TimingInfoFileName); - fputs("Output file: ", stdout); - puts(buffer); - - LogFileHandle = CreateFileA(buffer, - GENERIC_READ | GENERIC_WRITE, - 0, - NULL, - CREATE_ALWAYS, - FILE_ATTRIBUTE_NORMAL, - NULL); - - const char *titleLine = "CALLS/INDEX | THREAD | SECS | ACTION\n"; - WriteFile(LogFileHandle, titleLine, (DWORD)strlen(titleLine), nullptr, nullptr); - fputs(titleLine, stdout); - } - - snprintf(buffer, sizeof(buffer), "%11lld | %8x | %12.9f | %s\n", callCount, threadID, tickCount / (double)TimerFrequency, action); - fputs(buffer, stdout); - WriteFile(LogFileHandle, buffer, (DWORD)strlen(buffer), nullptr, nullptr); -#endif -} - -void FlushTimingInfo() -{ - if (LogFileHandle != INVALID_HANDLE_VALUE) - { - FlushFileBuffers(LogFileHandle); - CloseHandle(LogFileHandle); - LogFileHandle = INVALID_HANDLE_VALUE; - } -} - static const int TypeNameBufferSize = 65536; static char TypeNameBuffer[TypeNameBufferSize]; From cb828b35ca006920010dbc286f586e9f9fdcaef5 Mon Sep 17 00:00:00 2001 From: Tomas Rylek Date: Sat, 25 Nov 2023 19:28:16 +0100 Subject: [PATCH 4/7] Revert metadata instrumentation; detailed instrumentation of type load --- src/coreclr/md/inc/metamodelro.h | 54 -------- src/coreclr/md/runtime/mdinternalro.cpp | 156 ------------------------ src/coreclr/md/runtime/metamodelro.cpp | 120 ------------------ src/coreclr/vm/appdomain.cpp | 20 +-- src/coreclr/vm/class.cpp | 4 + src/coreclr/vm/clsload.cpp | 22 +++- src/coreclr/vm/common.h | 54 ++++++++ src/coreclr/vm/corhost.cpp | 7 +- src/coreclr/vm/methodtablebuilder.cpp | 108 ++++++++++++++++ 9 files changed, 187 insertions(+), 358 deletions(-) diff --git a/src/coreclr/md/inc/metamodelro.h b/src/coreclr/md/inc/metamodelro.h index 7cd6499711e8f..de229263cbdce 100644 --- a/src/coreclr/md/inc/metamodelro.h +++ b/src/coreclr/md/inc/metamodelro.h @@ -20,60 +20,6 @@ #include "../heaps/export.h" #include "../tables/export.h" -int64_t GetPreciseTickCount(); - -class MDInstrumentedMethod -{ -public: - class Execution - { - private: - MDInstrumentedMethod *_instrumentedMethod; - int64_t _startTicks; - - public: - Execution(MDInstrumentedMethod *method) - : _instrumentedMethod(method) - { -#ifndef DACCESS_COMPILE - _startTicks = GetPreciseTickCount(); -#endif - } - - ~Execution() - { -#ifndef DACCESS_COMPILE - _instrumentedMethod->Add(GetPreciseTickCount() - _startTicks); -#endif - } - }; - -private: - static MDInstrumentedMethod *s_list; - - const char *_methodName; - int64_t _count; - int64_t _ticks; - MDInstrumentedMethod *_next; - -public: - MDInstrumentedMethod(const char *methodName); - - static void DumpAllTiming(); - void Add(int64_t ticks); - -private: - void DumpTiming(); -}; - -#ifdef MD_INSTRUMENTATION -#define MD_INSTRUMENTED_METHOD(name) \ - static MDInstrumentedMethod s_instrumentedMethod(name); \ - MDInstrumentedMethod::Execution methodExecution(&s_instrumentedMethod); -#else -#define MD_INSTRUMENTED_METHOD(name) -#endif - //***************************************************************************** // A read-only MiniMd. This is the fastest and smallest possible MiniMd, // and as such, is the preferred EE metadata provider. diff --git a/src/coreclr/md/runtime/mdinternalro.cpp b/src/coreclr/md/runtime/mdinternalro.cpp index 6cf4d3390c2e3..25bdda172f010 100644 --- a/src/coreclr/md/runtime/mdinternalro.cpp +++ b/src/coreclr/md/runtime/mdinternalro.cpp @@ -96,8 +96,6 @@ ULONG MDInternalRO::Release() __checkReturn HRESULT MDInternalRO::QueryInterface(REFIID riid, void **ppUnk) { - MD_INSTRUMENTED_METHOD("MDInternalRO::QueryInterface") - *ppUnk = 0; if (riid == IID_IUnknown) @@ -121,8 +119,6 @@ HRESULT MDInternalRO::Init( LPVOID pData, // points to meta data section in memory ULONG cbData) // count of bytes in pData { - MD_INSTRUMENTED_METHOD("MDInternalRO::Init"); - m_tdModule = COR_GLOBAL_PARENT_TOKEN; extern HRESULT _CallInitOnMemHelper(CLiteWeightStgdb *pStgdb, ULONG cbData, LPCVOID pData); @@ -146,8 +142,6 @@ HRESULT MDInternalRO::TranslateSigWithScope( CQuickBytes* pqkSigEmit, // [OUT] buffer to hold translated signature ULONG* pcbSig) // [OUT] count of bytes in the translated signature { - MD_INSTRUMENTED_METHOD("MDInternalRO::TranslateSigWithScope"); - return TranslateSigHelper( this, pAssemImport, @@ -167,8 +161,6 @@ HRESULT MDInternalRO::GetTypeDefRefTokenInTypeSpec(// return S_FALSE if enclosin mdTypeSpec tkTypeSpec, // [IN] TypeSpec token to look at mdToken *tkEnclosedToken) // [OUT] The enclosed type token { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetTypeDefRefTokenInTypeSpec"); - return m_LiteWeightStgdb.m_MiniMd.GetTypeDefRefTokenInTypeSpec(tkTypeSpec, tkEnclosedToken); } // MDInternalRO::GetTypeDefRefTokenInTypeSpec @@ -179,8 +171,6 @@ HRESULT MDInternalRO::GetTypeDefRefTokenInTypeSpec(// return S_FALSE if enclosin ULONG MDInternalRO::GetCountWithTokenKind( // return hresult DWORD tkKind) // [IN] pass in the kind of token. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetCountWithTokenKind"); - ULONG ulCount = m_LiteWeightStgdb.m_MiniMd.CommonGetRowCount(tkKind); if (tkKind == mdtTypeDef) { @@ -204,8 +194,6 @@ __checkReturn HRESULT MDInternalRO::EnumTypeDefInit( // return hresult HENUMInternal *phEnum) // [OUT] buffer to fill for enumerator data { - MD_INSTRUMENTED_METHOD("MDInternalRO::EnumTypeDefInit"); - HRESULT hr = NOERROR; _ASSERTE(phEnum); @@ -238,8 +226,6 @@ HRESULT MDInternalRO::EnumMethodImplInit( // return hresult HENUMInternal *phEnumBody, // [OUT] buffer to fill for enumerator data for MethodBody tokens. HENUMInternal *phEnumDecl) // [OUT] buffer to fill for enumerator data for MethodDecl tokens. { - MD_INSTRUMENTED_METHOD("MDInternalRO::EnumMethodImplInit"); - return EnumInit(TBL_MethodImpl << 24, td, phEnumBody); } // MDInternalRO::EnumMethodImplInit @@ -266,8 +252,6 @@ MDInternalRO::EnumMethodImplNext( // return hresult mdToken *ptkBody, // [OUT] return token for MethodBody mdToken *ptkDecl) // [OUT] return token for MethodDecl { - MD_INSTRUMENTED_METHOD("MDInternalRO::EnumMethodImplNext"); - HRESULT hr; MethodImplRec *pRecord; @@ -344,8 +328,6 @@ HRESULT MDInternalRO::EnumInit( // return S_FALSE if record not found mdToken tkParent, // [IN] token to scope the search HENUMInternal *phEnum) // [OUT] the enumerator to fill { - MD_INSTRUMENTED_METHOD("MDInternalRO::EnumInit"); - HRESULT hr = S_OK; ULONG ulMax = 0; @@ -515,8 +497,6 @@ HRESULT MDInternalRO::EnumAllInit( // return S_FALSE if record not found DWORD tkKind, // [IN] which table to work on HENUMInternal *phEnum) // [OUT] the enumerator to fill { - MD_INSTRUMENTED_METHOD("MDInternalRO::EnumAllInit"); - HRESULT hr = S_OK; // Vars for query. @@ -597,8 +577,6 @@ HRESULT MDInternalRO::EnumCustomAttributeByNameInit(// return S_FALSE if record LPCSTR szName, // [IN] CustomAttribute's name to scope the search HENUMInternal *phEnum) // [OUT] the enumerator to fill { - MD_INSTRUMENTED_METHOD("MDInternalRO::EnumCustomAttributeByNameInit"); - return m_LiteWeightStgdb.m_MiniMd.CommonEnumCustomAttributeByName(tkParent, szName, false, phEnum); } // MDInternalRO::EnumCustomAttributeByNameInit @@ -621,8 +599,6 @@ HRESULT MDInternalRO::GetParentToken( mdToken tkChild, // [IN] given child token mdToken *ptkParent) // [OUT] returning parent { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetParentToken"); - HRESULT hr = NOERROR; _ASSERTE(ptkParent); @@ -703,8 +679,6 @@ MDInternalRO::GetCustomAttributeProps( // S_OK or error. mdCustomAttribute at, // The attribute. mdToken *ptkType) // Put attribute type here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetCustomAttributeProps"); - HRESULT hr; _ASSERTE(TypeFromToken(at) == mdtCustomAttribute); @@ -728,8 +702,6 @@ MDInternalRO::GetCustomAttributeAsBlob( void const **ppBlob, // [OUT] return the pointer to internal blob ULONG *pcbSize) // [OUT] return the size of the blob { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetCustomAttributeAsBlob"); - HRESULT hr; _ASSERTE(ppBlob && pcbSize && TypeFromToken(cv) == mdtCustomAttribute); @@ -751,8 +723,6 @@ HRESULT MDInternalRO::GetCustomAttributeByName( // S_OK or error. _Outptr_result_bytebuffer_(*pcbData) const void **ppData, // [OUT] Put pointer to data here. _Out_ ULONG *pcbData) // [OUT] Put size of data here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetCustomAttributeByName"); - return m_LiteWeightStgdb.m_MiniMd.CommonGetCustomAttributeByNameEx(tkObj, szName, NULL, ppData, pcbData); } // MDInternalRO::GetCustomAttributeByName @@ -766,8 +736,6 @@ HRESULT MDInternalRO::GetNameOfCustomAttribute( // S_OK or error. LPCUTF8 *pszNamespace, // [OUT] Namespace of Custom Attribute. LPCUTF8 *pszName) // [OUT] Name of Custom Attribute. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfCustomAttribute"); - _ASSERTE(TypeFromToken(mdAttribute) == mdtCustomAttribute); HRESULT hr = m_LiteWeightStgdb.m_MiniMd.CommonGetNameOfCustomAttribute(RidFromToken(mdAttribute), pszNamespace, pszName); @@ -783,8 +751,6 @@ MDInternalRO::GetScopeProps( LPCSTR *pszName, // [OUT] scope name GUID *pmvid) // [OUT] version id { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetScopeProps"); - HRESULT hr; ModuleRec *pModuleRec; @@ -832,8 +798,6 @@ HRESULT MDInternalRO::FindMethodDef( // S_OK or error. ULONG cbSigBlob, // [IN] count of bytes in the signature blob mdMethodDef *pmethoddef) // Put MemberDef token here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindMethodDef"); - return FindMethodDefUsingCompare(classdef, szName, pvSigBlob, @@ -856,8 +820,6 @@ HRESULT MDInternalRO::FindMethodDefUsingCompare( // S_OK or error. void* pSigArgs, // [IN] Additional arguments passed to signature compare mdMethodDef *pmethoddef) // Put MemberDef token here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindMethodDefUsingCompare"); - HRESULT hr = NOERROR; PCCOR_SIGNATURE pvSigTemp = pvSigBlob; CQuickBytes qbSig; @@ -934,8 +896,6 @@ HRESULT MDInternalRO::FindParamOfMethod(// S_OK or error. ULONG iSeq, // [IN] The sequence # of the param. mdParamDef *pparamdef) // [OUT] Put ParamDef token here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindParamOfMethod"); - HRESULT hr; ParamRec *pParamRec; RID ridStart, ridEnd; @@ -984,8 +944,6 @@ MDInternalRO::GetNameOfTypeDef( // return hresult LPCSTR* pszname, // pointer to an internal UTF8 string LPCSTR* psznamespace) // pointer to the namespace. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfTypeDef"); - HRESULT hr; if (pszname != NULL) @@ -1024,8 +982,6 @@ HRESULT MDInternalRO::GetIsDualOfTypeDef(// return hresult mdTypeDef classdef, // given classdef ULONG *pDual) // [OUT] return dual flag here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetIsDualOfTypeDef"); - ULONG iFace=0; // Iface type. HRESULT hr; // A result. @@ -1043,8 +999,6 @@ HRESULT MDInternalRO::GetIfaceTypeOfTypeDef( mdTypeDef classdef, // [IN] given classdef. ULONG *pIface) // [OUT] 0=dual, 1=vtable, 2=dispinterface { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetIfaceTypeOfTypeDef"); - HRESULT hr; // A result. const BYTE *pVal; // The custom value. ULONG cbVal; // Size of the custom value. @@ -1080,8 +1034,6 @@ MDInternalRO::GetNameOfMethodDef( mdMethodDef md, LPCSTR *pszMethodName) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfMethodDef"); - HRESULT hr; MethodRec *pMethodRec; *pszMethodName = NULL; @@ -1101,8 +1053,6 @@ MDInternalRO::GetNameAndSigOfMethodDef( ULONG *pcbSigBlob, // [OUT] count of bytes in the signature blob LPCSTR *pszMethodName) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameAndSigOfMethodDef"); - HRESULT hr; // Output parameter should not be NULL _ASSERTE(ppvSigBlob && pcbSigBlob); @@ -1127,8 +1077,6 @@ MDInternalRO::GetNameOfFieldDef( // return hresult mdFieldDef fd, // given field LPCSTR *pszFieldName) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfFieldDef"); - HRESULT hr; FieldRec *pFieldRec; *pszFieldName = NULL; @@ -1149,8 +1097,6 @@ MDInternalRO::GetNameOfTypeRef( // return TypeDef's name LPCSTR *pszname) // [OUT] return typeref namespace { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameOfTypeRef"); - _ASSERTE(TypeFromToken(classref) == mdtTypeRef); HRESULT hr; @@ -1174,8 +1120,6 @@ MDInternalRO::GetResolutionScopeOfTypeRef( mdTypeRef classref, // given classref mdToken *ptkResolutionScope) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetResolutionScopeOfTypeRef"); - _ASSERTE(TypeFromToken(classref) == mdtTypeRef && RidFromToken(classref)); HRESULT hr; @@ -1197,8 +1141,6 @@ HRESULT MDInternalRO::FindTypeRefByName( // S_OK or error. mdToken tkResolutionScope, // [IN] Resolution Scope fo the TypeRef. mdTypeRef *ptk) // [OUT] TypeRef token returned. { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindTypeRefByName"); - HRESULT hr = NOERROR; _ASSERTE(ptk); @@ -1259,8 +1201,6 @@ HRESULT MDInternalRO::GetTypeDefProps( DWORD *pdwAttr, // return flags on class mdToken *ptkExtends) // [OUT] Put base class TypeDef/TypeRef here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetTypeDefProps"); - HRESULT hr; TypeDefRec *pTypeDefRec; IfFailRet(m_LiteWeightStgdb.m_MiniMd.GetTypeDefRecord(RidFromToken(td), &pTypeDefRec)); @@ -1286,8 +1226,6 @@ HRESULT MDInternalRO::GetItemGuid( // return hresult mdToken tkObj, // given item CLSID *pGuid) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetItemGuid"); - HRESULT hr; // A result. const BYTE *pBlob = NULL; // Blob with dispid. ULONG cbBlob; // Length of blob. @@ -1326,8 +1264,6 @@ HRESULT MDInternalRO::GetNestedClassProps( // S_OK or error mdTypeDef tkNestedClass, // [IN] NestedClass token. mdTypeDef *ptkEnclosingClass) // [OUT] EnclosingClass token. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNestedClassProps"); - HRESULT hr; _ASSERTE(TypeFromToken(tkNestedClass) == mdtTypeDef && ptkEnclosingClass); @@ -1356,8 +1292,6 @@ MDInternalRO::GetCountNestedClasses( // return count of Nested classes. mdTypeDef tkEnclosingClass, // [IN]Enclosing class. ULONG *pcNestedClassesCount) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetCountNestedClasses"); - HRESULT hr; ULONG ulCount; ULONG ulRetCount = 0; @@ -1390,8 +1324,6 @@ MDInternalRO::GetNestedClasses( // Return actual count. ULONG ulNestedClasses, // [IN] Size of array. ULONG *pcNestedClasses) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNestedClasses"); - HRESULT hr; ULONG ulCount; ULONG ulRetCount = 0; @@ -1426,8 +1358,6 @@ HRESULT MDInternalRO::GetModuleRefProps( // return hresult mdModuleRef mur, // [IN] moduleref token LPCSTR *pszName) // [OUT] buffer to fill with the moduleref name { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetModuleRefProps"); - _ASSERTE(TypeFromToken(mur) == mdtModuleRef); _ASSERTE(pszName); @@ -1459,8 +1389,6 @@ MDInternalRO::GetSigOfMethodDef( ULONG *pcbSigBlob, // [OUT] count of bytes in the signature blob PCCOR_SIGNATURE *ppSig) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetSigOfMethodDef"); - // Output parameter should not be NULL _ASSERTE(pcbSigBlob); _ASSERTE(TypeFromToken(methoddef) == mdtMethodDef); @@ -1485,8 +1413,6 @@ MDInternalRO::GetSigOfFieldDef( ULONG *pcbSigBlob, // [OUT] count of bytes in the signature blob PCCOR_SIGNATURE *ppSig) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetSigOfFieldDef"); - _ASSERTE(pcbSigBlob); _ASSERTE(TypeFromToken(fielddef) == mdtFieldDef); @@ -1509,8 +1435,6 @@ MDInternalRO::GetSigFromToken( ULONG * pcbSig, PCCOR_SIGNATURE * ppSig) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetSigFromToken"); - HRESULT hr; *ppSig = NULL; @@ -1558,8 +1482,6 @@ MDInternalRO::GetMethodDefProps( mdMethodDef md, DWORD *pdwFlags) // return mdPublic, mdAbstract, etc { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetMethodDefProps"); - HRESULT hr; MethodRec *pMethodRec; @@ -1579,8 +1501,6 @@ HRESULT MDInternalRO::GetMethodImplProps( ULONG *pulCodeRVA, // [OUT] CodeRVA DWORD *pdwImplFlags) // [OUT] Impl. Flags { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetMethodImplProps"); - HRESULT hr; _ASSERTE(TypeFromToken(tk) == mdtMethodDef); @@ -1609,8 +1529,6 @@ HRESULT MDInternalRO::GetFieldRVA( mdToken fd, // [IN] FieldDef ULONG *pulCodeRVA) // [OUT] CodeRVA { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetFieldRVA"); - HRESULT hr; _ASSERTE(TypeFromToken(fd) == mdtFieldDef); _ASSERTE(pulCodeRVA); @@ -1641,8 +1559,6 @@ MDInternalRO::GetFieldDefProps( mdFieldDef fd, // given memberdef DWORD *pdwFlags) // [OUT] return fdPublic, fdPrive, etc flags { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetFieldDefProps"); - HRESULT hr; _ASSERTE(TypeFromToken(fd) == mdtFieldDef); @@ -1663,8 +1579,6 @@ HRESULT MDInternalRO::GetDefaultValue( // return hresult mdToken tk, // [IN] given FieldDef, ParamDef, or Property MDDefaultValue *pMDDefaultValue) // [OUT] default value { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetDefaultValue"); - _ASSERTE(pMDDefaultValue); HRESULT hr; @@ -1699,8 +1613,6 @@ HRESULT MDInternalRO::GetDispIdOfMemberDef( // return hresult mdToken tk, // given methoddef or fielddef ULONG *pDispid) // Put the dispid here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetDispIdOfMemberDef"); - #ifdef FEATURE_COMINTEROP HRESULT hr; // A result. const BYTE *pBlob; // Blob with dispid. @@ -1737,8 +1649,6 @@ MDInternalRO::GetTypeOfInterfaceImpl( // return hresult mdInterfaceImpl iiImpl, // given a interfaceimpl mdToken *ptkType) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetTypeOfInterfaceImpl"); - HRESULT hr; _ASSERTE(TypeFromToken(iiImpl) == mdtInterfaceImpl); @@ -1760,8 +1670,6 @@ HRESULT MDInternalRO::GetMethodSpecProps( // S_OK or error. PCCOR_SIGNATURE *ppvSigBlob, // [OUT] point to the blob value of meta data ULONG *pcbSigBlob) // [OUT] actual size of signature blob { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetMethodSpecProps"); - HRESULT hr = NOERROR; MethodSpecRec *pMethodSpecRec; @@ -1801,8 +1709,6 @@ MDInternalRO::FindTypeDef( mdToken tkEnclosingClass, // [IN] TypeDef/TypeRef of enclosing class. mdTypeDef * ptkTypeDef) // [OUT] return typedef { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindTypeDef"); - HRESULT hr = S_OK; _ASSERTE((szTypeDefName != NULL) && (ptkTypeDef != NULL)); @@ -1908,8 +1814,6 @@ MDInternalRO::GetNameAndSigOfMemberRef( // meberref's name ULONG *pcbSigBlob, // [OUT] count of bytes in the signature blob LPCSTR *pszMemberRefName) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetNameAndSigOfMemberRef"); - _ASSERTE(TypeFromToken(memberref) == mdtMemberRef); HRESULT hr; @@ -1939,8 +1843,6 @@ MDInternalRO::GetParentOfMemberRef( mdMemberRef memberref, // given a typedef mdToken *ptkParent) // return the parent token { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetParentOfMemberRef"); - HRESULT hr; _ASSERTE(TypeFromToken(memberref) == mdtMemberRef); @@ -1964,8 +1866,6 @@ MDInternalRO::GetParamDefProps ( DWORD *pdwAttr, // [OUT] flags LPCSTR *pszName) // [OUT] return the name of the parameter { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetParamDefProps"); - _ASSERTE(TypeFromToken(paramdef) == mdtParamDef); HRESULT hr; ParamRec *pParamRec; @@ -2018,8 +1918,6 @@ HRESULT MDInternalRO::GetPropertyInfoForMethodDef( // Result. LPCSTR *pName, // [OUT] put pointer to name here ULONG *pSemantic) // [OUT] put semantic here { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetPropertyInfoForMethodDef"); - HRESULT hr; MethodSemanticsRec *pSemantics; // A MethodSemantics record. MethodSemanticsRec *pFound=0; // A MethodSemantics record that is a property for the desired function. @@ -2177,8 +2075,6 @@ HRESULT MDInternalRO::GetClassPackSize( mdTypeDef td, // [IN] give typedef DWORD *pdwPackSize) // [OUT] { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetClassPackSize"); - HRESULT hr = NOERROR; _ASSERTE(TypeFromToken(td) == mdtTypeDef && pdwPackSize); @@ -2208,8 +2104,6 @@ HRESULT MDInternalRO::GetClassTotalSize( // return error if a class does not hav mdTypeDef td, // [IN] give typedef ULONG *pulClassSize) // [OUT] return the total size of the class { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetClassTotalSize"); - _ASSERTE(TypeFromToken(td) == mdtTypeDef && pulClassSize); ClassLayoutRec *pRec; @@ -2238,8 +2132,6 @@ HRESULT MDInternalRO::GetClassLayoutInit( mdTypeDef td, // [IN] give typedef MD_CLASS_LAYOUT *pmdLayout) // [OUT] set up the status of query here { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetClassLayoutInit"); - HRESULT hr = NOERROR; _ASSERTE(TypeFromToken(td) == mdtTypeDef); @@ -2267,8 +2159,6 @@ HRESULT MDInternalRO::GetFieldOffset( mdFieldDef fd, // [IN] fielddef ULONG *pulOffset) // [OUT] FieldOffset { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetFieldOffset"); - HRESULT hr = S_OK; FieldLayoutRec *pRec; @@ -2302,8 +2192,6 @@ HRESULT MDInternalRO::GetClassLayoutNext( mdFieldDef *pfd, // [OUT] field def ULONG *pulOffset) // [OUT] field offset or sequence { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetClassLayoutNext"); - HRESULT hr = S_OK; _ASSERTE(pfd && pulOffset && pLayout); @@ -2346,8 +2234,6 @@ HRESULT MDInternalRO::GetFieldMarshal( // return error if no native type associ PCCOR_SIGNATURE *pSigNativeType, // [OUT] the native type signature ULONG *pcbNativeType) // [OUT] the count of bytes of *ppvNativeType { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetFieldMarshal"); - // output parameters have to be supplied _ASSERTE(pcbNativeType); @@ -2387,8 +2273,6 @@ HRESULT MDInternalRO::FindProperty( LPCSTR szPropName, // [IN] property name mdProperty *pProp) // [OUT] return property token { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindProperty"); - HRESULT hr = NOERROR; // output parameters have to be supplied @@ -2447,8 +2331,6 @@ HRESULT MDInternalRO::GetPropertyProps( PCCOR_SIGNATURE *ppvSig, // [OUT] property type. pointing to meta data internal blob ULONG *pcbSig) // [OUT] count of bytes in *ppvSig { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetPropertyProps"); - // output parameters have to be supplied _ASSERTE(TypeFromToken(prop) == mdtProperty); @@ -2498,8 +2380,6 @@ HRESULT MDInternalRO::FindEvent( LPCSTR szEventName, // [IN] event name mdEvent *pEvent) // [OUT] return event token { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindEvent"); - HRESULT hr = NOERROR; // output parameters have to be supplied @@ -2554,8 +2434,6 @@ HRESULT MDInternalRO::GetEventProps( // S_OK, S_FALSE, or error. DWORD *pdwEventFlags, // [OUT] Event flags. mdToken *ptkEventType) // [OUT] EventType class { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetEventProps"); - // output parameters have to be supplied _ASSERTE(TypeFromToken(ev) == mdtEvent); @@ -2587,8 +2465,6 @@ HRESULT MDInternalRO::GetGenericParamProps( // S_OK or error. DWORD *reserved, // [OUT] The kind (TypeDef/Ref/Spec, for future use) LPCSTR *szName) // [OUT] The name { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetGenericParamProps"); - HRESULT hr = NOERROR; GenericParamRec * pGenericParamRec = NULL; @@ -2627,8 +2503,6 @@ HRESULT MDInternalRO::GetGenericParamConstraintProps( // S_OK or error. mdGenericParam *ptGenericParam, // [OUT] GenericParam that is constrained mdToken *ptkConstraintType) // [OUT] TypeDef/Ref/Spec constraint { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetGenericParamConstraintProps"); - HRESULT hr = NOERROR; GenericParamConstraintRec *pGPCRec; RID ridRD = RidFromToken(rd); @@ -2699,8 +2573,6 @@ HRESULT MDInternalRO::EnumAssociateInit( mdToken evprop, // [IN] given a property or an event token HENUMInternal *phEnum) // [OUT] cursor to hold the query result { - MD_INSTRUMENTED_METHOD("MDInternalRO::EnumAssociateInit"); - HRESULT hr; _ASSERTE(phEnum); @@ -2730,8 +2602,6 @@ HRESULT MDInternalRO::GetAllAssociates( ASSOCIATE_RECORD *pAssociateRec, // [OUT] struct to fill for output ULONG cAssociateRec) // [IN] size of the buffer { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetAllAssociates"); - _ASSERTE(phEnum && pAssociateRec); HRESULT hr; @@ -2762,8 +2632,6 @@ HRESULT MDInternalRO::GetPermissionSetProps( void const **ppvPermission, // [OUT] permission blob. ULONG *pcbPermission) // [OUT] count of bytes of pvPermission. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetPermissionSetProps"); - HRESULT hr; _ASSERTE(TypeFromToken(pm) == mdtPermission); _ASSERTE(pdwAction && ppvPermission && pcbPermission); @@ -2789,8 +2657,6 @@ MDInternalRO::GetUserString( // Offset into the string blob heap. BOOL *pfIs80Plus, // [OUT] specifies where there are extended characters >= 0x80. LPCWSTR *pwszUserString) { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetUserString"); - HRESULT hr; LPWSTR wszTmp; @@ -2839,8 +2705,6 @@ HRESULT MDInternalRO::GetPinvokeMap( LPCSTR *pszImportName, // [OUT] Import name. mdModuleRef *pmrImportDLL) // [OUT] ModuleRef token for the target DLL. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetPinvokeMap"); - HRESULT hr; ImplMapRec *pRecord; RID iRecord; @@ -2880,8 +2744,6 @@ HRESULT MDInternalRO::GetAssemblyProps( AssemblyMetaDataInternal *pMetaData,// [OUT] Assembly MetaData. DWORD *pdwAssemblyFlags) // [OUT] Flags. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetAssemblyProps"); - HRESULT hr; AssemblyRec *pRecord; @@ -2935,8 +2797,6 @@ HRESULT MDInternalRO::GetAssemblyRefProps( ULONG *pcbHashValue, // [OUT] Count of bytes in the hash blob. DWORD *pdwAssemblyRefFlags) // [OUT] Flags. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetAssemblyRefProps"); - HRESULT hr; AssemblyRefRec *pRecord; @@ -3016,8 +2876,6 @@ HRESULT MDInternalRO::GetExportedTypeProps( mdTypeDef *ptkTypeDef, // [OUT] TypeDef token within the file. DWORD *pdwExportedTypeFlags) // [OUT] Flags. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetExportedTypeProps"); - HRESULT hr; ExportedTypeRec *pRecord; @@ -3053,8 +2911,6 @@ HRESULT MDInternalRO::GetManifestResourceProps( DWORD *pdwOffset, // [OUT] Offset to the beginning of the resource within the file. DWORD *pdwResourceFlags) // [OUT] Flags. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetManifestResourceProps"); - HRESULT hr; ManifestResourceRec *pRecord; @@ -3085,8 +2941,6 @@ STDMETHODIMP MDInternalRO::FindExportedTypeByName( // S_OK or error mdExportedType tkEnclosingType, // [IN] Token for the Enclosing Type. mdExportedType *pmct) // [OUT] Put ExportedType token here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindExportedTypeByName"); - IMetaModelCommon *pCommon = static_cast(&m_LiteWeightStgdb.m_MiniMd); return pCommon->CommonFindExportedType(szNamespace, szName, tkEnclosingType, pmct); } // MDInternalRO::FindExportedTypeByName @@ -3099,8 +2953,6 @@ STDMETHODIMP MDInternalRO::FindManifestResourceByName( // S_OK or error LPCSTR szName, // [IN] Name of the resource. mdManifestResource *pmmr) // [OUT] Put ManifestResource token here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::FindManifestResourceByName"); - _ASSERTE(szName && pmmr); HRESULT hr; @@ -3132,8 +2984,6 @@ __checkReturn HRESULT MDInternalRO::GetAssemblyFromScope( // S_OK or error mdAssembly *ptkAssembly) // [OUT] Put token here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetAssemblyFromScope"); - _ASSERTE(ptkAssembly); if (m_LiteWeightStgdb.m_MiniMd.getCountAssemblys()) @@ -3154,8 +3004,6 @@ HRESULT MDInternalRO::GetTypeSpecFromToken( // S_OK or error. PCCOR_SIGNATURE *ppvSig, // [OUT] return pointer to token. ULONG *pcbSig) // [OUT] return size of signature. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetTypeSpecFromToken"); - HRESULT hr = NOERROR; _ASSERTE(TypeFromToken(typespec) == mdtTypeSpec); @@ -3192,8 +3040,6 @@ __checkReturn HRESULT MDInternalRO::GetVersionString( LPCSTR * pVer) // [OUT] Put version string here. { - MD_INSTRUMENTED_METHOD("MDInternalRO::GetVersionString"); - HRESULT hr = NOERROR; if (m_LiteWeightStgdb.m_pvMd != NULL) @@ -3230,8 +3076,6 @@ HRESULT MDInternalRO::ConvertTextSigToComSig(// Return hresult. BOOL MDInternalRO::IsValidToken( // True or False. mdToken tk) // [IN] Given token. { - MD_INSTRUMENTED_METHOD("MDInternalRO::IsValidToken"); - RID rid = RidFromToken(tk); if (rid == 0) { diff --git a/src/coreclr/md/runtime/metamodelro.cpp b/src/coreclr/md/runtime/metamodelro.cpp index df4a623be4555..67783a2cf39ea 100644 --- a/src/coreclr/md/runtime/metamodelro.cpp +++ b/src/coreclr/md/runtime/metamodelro.cpp @@ -12,110 +12,6 @@ #include #include -static volatile HANDLE LogFileHandle = INVALID_HANDLE_VALUE; -static volatile int64_t TimerFrequency = 0; - -void DumpMetadataTimingInfo() -{ - MDInstrumentedMethod::DumpAllTiming(); -} - -int64_t GetPreciseTickCount() -{ - int64_t result; - QueryPerformanceCounter((LARGE_INTEGER *)&result); - return result; -} - -void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount) -{ - static long timingCallCount = 0; - static const int BufferSize = 1024; - static char buffer[BufferSize]; - static const char *TimingInfoFileName = -#ifdef TARGET_WINDOWS - "\\" -#else - "/" -#endif - "timing-info.txt"; - - if (LogFileHandle == INVALID_HANDLE_VALUE) - { - QueryPerformanceFrequency((LARGE_INTEGER *)&TimerFrequency); - GetCurrentDirectoryA(BufferSize, buffer); - strcat_s(buffer, BufferSize, TimingInfoFileName); - fputs("Output file: ", stdout); - puts(buffer); - - LogFileHandle = CreateFileA(buffer, - GENERIC_READ | GENERIC_WRITE, - 0, - NULL, - CREATE_ALWAYS, - FILE_ATTRIBUTE_NORMAL, - NULL); - - const char *titleLine = "CALLS/INDEX | THREAD | SECS | ACTION\n"; - WriteFile(LogFileHandle, titleLine, (DWORD)strlen(titleLine), nullptr, nullptr); - fputs(titleLine, stdout); - } - - snprintf(buffer, sizeof(buffer), "%11lld | %8x | %12.9f | %s\n", callCount, threadID, tickCount / (double)TimerFrequency, action); - fputs(buffer, stdout); - WriteFile(LogFileHandle, buffer, (DWORD)strlen(buffer), nullptr, nullptr); -} - -void FlushTimingInfo() -{ - if (LogFileHandle != INVALID_HANDLE_VALUE) - { - FlushFileBuffers(LogFileHandle); - CloseHandle(LogFileHandle); - LogFileHandle = INVALID_HANDLE_VALUE; - } -} - -MDInstrumentedMethod *MDInstrumentedMethod::s_list = nullptr; - -MDInstrumentedMethod::MDInstrumentedMethod(const char *methodName) -{ - _methodName = methodName; - _count = 0; - _ticks = 0; - _next = InterlockedExchangeT(&s_list, this); -} - -void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount); - -void MDInstrumentedMethod::DumpAllTiming() -{ - int64_t sumCount = 0; - int64_t sumTicks = 0; - - for (MDInstrumentedMethod *list = s_list; list != nullptr; list = list->_next) - { - list->DumpTiming(); - sumCount += list->_count; - sumTicks += list->_ticks; - } - - DumpTimingInfo("MDInstrumentedMethod", 0, sumCount, sumTicks); -} - -void MDInstrumentedMethod::DumpTiming() -{ -#if !defined(DACCESS_COMPILE) - DumpTimingInfo(_methodName, 0, _count, _ticks); -#endif -} - -void MDInstrumentedMethod::Add(int64_t ticks) -{ - InterlockedIncrement64(&_count); - InterlockedAdd64(&_ticks, ticks); -} - //***************************************************************************** // Set the pointers to consecutive areas of a large buffer. //***************************************************************************** @@ -124,8 +20,6 @@ HRESULT CMiniMd::InitializeTables( MetaData::DataBlob tablesData) { - // MD_INSTRUMENTED_METHOD("CMiniMd::InitializeTables") - HRESULT hr; for (int i = 0; i < TBL_COUNT; i++) @@ -165,8 +59,6 @@ CMiniMd::InitOnMem( void *pvBuf, // The buffer. ULONG ulBufLen) // Size of the buffer.. { - // MD_INSTRUMENTED_METHOD("CMiniMd::InitOnMem") - HRESULT hr = S_OK; ULONG cbData; BYTE *pBuf = reinterpret_cast(pvBuf); @@ -209,8 +101,6 @@ CMiniMd::Impl_GetStringW( ULONG cchBuffer, ULONG *pcchBuffer) { - // MD_INSTRUMENTED_METHOD("CMiniMd::Impl_GetStringW") - LPCSTR szString; // Single byte version. int iSize; // Size of resulting string, in wide chars. HRESULT hr = NOERROR; @@ -271,8 +161,6 @@ CMiniMd::Impl_GetEndRidForColumn( // The End rid. UINT32 nTargetTableIndex, // The other table. RID *pEndRid) { - // MD_INSTRUMENTED_METHOD("CMiniMd::Impl_GetEndRidForColumn") - HRESULT hr; _ASSERTE(nTableIndex < TBL_COUNT); RID nLastRowIndex = m_Schema.m_cRecs[nTableIndex]; @@ -309,8 +197,6 @@ CMiniMd::CommonEnumCustomAttributeByName( bool fStopAtFirstFind, // [IN] just find the first one HENUMInternal *phEnum) // enumerator to fill up { - // MD_INSTRUMENTED_METHOD("CMiniMd::CommonEnumCustomAttributeByName") - HRESULT hr = S_OK; HRESULT hrRet = S_FALSE; // Assume that we won't find any RID ridStart, ridEnd; // Loop start and endpoints. @@ -365,8 +251,6 @@ CMiniMd::vSearchTable( ULONG ulTarget, // Target for search. RID *pRid) // RID of matching row, or 0. { - // MD_INSTRUMENTED_METHOD("CMiniMd::vSearchTable") - HRESULT hr; void *pRow = NULL; // Row from a table. ULONG val; // Value from a row. @@ -412,8 +296,6 @@ CMiniMd::vSearchTableNotGreater( ULONG ulTarget, // target for search RID *pRid) // RID of matching row, or 0 { - // MD_INSTRUMENTED_METHOD("CMiniMd::vSearchTableNotGreater") - HRESULT hr; void *pRow = NULL; // Row from a table. ULONG cRecs; // Rows in the table. @@ -497,8 +379,6 @@ CMiniMd::CommonGetCustomAttributeByNameEx( const void **ppData, // [OUT] Put pointer to data here. ULONG *pcbData) // [OUT] Put size of data here. { - // MD_INSTRUMENTED_METHOD("CMiniMd::CommonGetCustomAttributeByNameEx") - HRESULT hr; ULONG cbData; diff --git a/src/coreclr/vm/appdomain.cpp b/src/coreclr/vm/appdomain.cpp index 0b84324f2f111..e5e4104883dc0 100644 --- a/src/coreclr/vm/appdomain.cpp +++ b/src/coreclr/vm/appdomain.cpp @@ -2559,25 +2559,10 @@ CHECK AppDomain::CheckCanExecuteManagedCode(MethodDesc* pMD) #endif // !DACCESS_COMPILE -static int64_t AssemblyLoadCallCount = 0; -static int64_t AssemblyLoadTickCount = 0; - -int64_t GetPreciseTickCount(); -void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount); - -void DumpAssemblyLoadTimingInfo() -{ -#ifndef DACCESS_COMPILE - DumpTimingInfo("AppDomain::LoadDomainAssembly", GetCurrentThreadId(), AssemblyLoadCallCount, AssemblyLoadTickCount); -#endif -} - void AppDomain::LoadDomainAssembly(DomainAssembly *pFile, FileLoadLevel targetLevel) { -#ifndef DACCESS_COMPILE - int64_t startTicks = GetPreciseTickCount(); -#endif + INSTRUMENTED_METHOD("AppDomain::LoadDomainAssembly"); CONTRACTL { @@ -2619,9 +2604,6 @@ void AppDomain::LoadDomainAssembly(DomainAssembly *pFile, LoadDomainAssembly(pLockEntry, targetLevel); } - InterlockedAdd64(&AssemblyLoadTickCount, GetPreciseTickCount() - startTicks); - InterlockedIncrement64(&AssemblyLoadCallCount); - #else // DACCESS_COMPILE DacNotImpl(); #endif // DACCESS_COMPILE diff --git a/src/coreclr/vm/class.cpp b/src/coreclr/vm/class.cpp index 0062632396c95..5974fb38fc96d 100644 --- a/src/coreclr/vm/class.cpp +++ b/src/coreclr/vm/class.cpp @@ -1043,6 +1043,8 @@ EEClass::CheckVarianceInSig( void ClassLoader::LoadExactParentAndInterfacesTransitively(MethodTable *pMT) { + INSTRUMENTED_METHOD("ClassLoader::LoadExactParentAndInterfacesTransitively"); + CONTRACTL { STANDARD_VM_CHECK; @@ -1200,6 +1202,8 @@ namespace /*static*/ void ClassLoader::LoadExactParents(MethodTable* pMT) { + INSTRUMENTED_METHOD("ClassLoader::LoadExactParents"); + CONTRACT_VOID { STANDARD_VM_CHECK; diff --git a/src/coreclr/vm/clsload.cpp b/src/coreclr/vm/clsload.cpp index b5aea64c9f37b..1b86a40050b73 100644 --- a/src/coreclr/vm/clsload.cpp +++ b/src/coreclr/vm/clsload.cpp @@ -2039,6 +2039,8 @@ TypeHandle ClassLoader::LoadTypeDefOrRefOrSpecThrowing(Module *pModule, const Substitution *pSubst, MethodTable *pMTInterfaceMapOwner) { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefOrSpecThrowing"); + CONTRACT(TypeHandle) { if (FORBIDGC_LOADER_USE_ENABLED()) NOTHROW; else THROWS; @@ -2846,6 +2848,8 @@ ClassLoader::LoadApproxParentThrowing( /*static*/ TypeHandle ClassLoader::DoIncrementalLoad(TypeKey *pTypeKey, TypeHandle typeHnd, ClassLoadLevel currentLevel) { + INSTRUMENTED_METHOD("ClassLoader::DoIncrementalLoad"); + CONTRACTL { STANDARD_VM_CHECK; @@ -2873,6 +2877,8 @@ TypeHandle ClassLoader::DoIncrementalLoad(TypeKey *pTypeKey, TypeHandle typeHnd, // or at least level CLASS_LOAD_APPROXPARENTS (if creating type for the first time) case CLASS_LOAD_BEGIN : { + INSTRUMENTED_METHOD("ClassLoader::DoIncrementalLoad / CLASS_LOAD_BEGIN"); + AllocMemTracker amTracker; typeHnd = CreateTypeHandleForTypeKey(pTypeKey, &amTracker); CONSISTENCY_CHECK(!typeHnd.IsNull()); @@ -2894,6 +2900,7 @@ TypeHandle ClassLoader::DoIncrementalLoad(TypeKey *pTypeKey, TypeHandle typeHnd, case CLASS_LOAD_APPROXPARENTS : if (!typeHnd.IsTypeDesc()) { + INSTRUMENTED_METHOD("ClassLoader::DoIncrementalLoad / CLASS_LOAD_APPROXPARENTS"); LoadExactParents(typeHnd.AsMethodTable()); } break; @@ -2907,6 +2914,7 @@ TypeHandle ClassLoader::DoIncrementalLoad(TypeKey *pTypeKey, TypeHandle typeHnd, if (typeHnd.GetLoadLevel() >= CLASS_LOAD_EXACTPARENTS) { + INSTRUMENTED_METHOD("ClassLoader::DoIncrementalLoad / Notify"); Notify(typeHnd); } @@ -3231,8 +3239,6 @@ static void PushFinalLevels(TypeHandle typeHnd, ClassLoadLevel targetLevel, cons } } - -int64_t GetPreciseTickCount(); void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks); // @@ -3241,6 +3247,9 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, ClassLoadLevel targetLevel/*=CLASS_LOADED*/, const InstantiationContext *pInstContext/*=NULL*/) { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeHandleForTypeKey"); + int64_t startTicks = GetPreciseTickCount(); + CONTRACTL { INSTANCE_CHECK; @@ -3267,7 +3276,6 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, #if defined(FEATURE_EVENT_TRACE) UINT32 typeLoad = ETW::TypeSystemLog::TypeLoadBegin(); #endif - int64_t startTicks = GetPreciseTickCount(); ClassLoadLevel currentLevel = typeHnd.IsNull() ? CLASS_LOAD_BEGIN : typeHnd.GetLoadLevel(); ClassLoadLevel targetLevelUnderLock = targetLevel < CLASS_DEPENDENCIES_LOADED ? targetLevel : (ClassLoadLevel) (CLASS_DEPENDENCIES_LOADED-1); @@ -3282,8 +3290,6 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, PushFinalLevels(typeHnd, targetLevel, pInstContext); - RecordTypeLoadTime(typeHnd, GetPreciseTickCount() - startTicks); - #if defined(FEATURE_EVENT_TRACE) if (ETW_EVENT_ENABLED(MICROSOFT_WINDOWS_DOTNETRUNTIME_PROVIDER_DOTNET_Context, TypeLoadStop)) { @@ -3291,6 +3297,8 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, } #endif + RecordTypeLoadTime(typeHnd, GetPreciseTickCount() - startTicks); + return typeHnd; } @@ -3384,6 +3392,8 @@ ClassLoader::LoadTypeHandleForTypeKey_Body( TypeHandle typeHnd, ClassLoadLevel targetLevel) { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeHandleForTypeKey_Body"); + CONTRACT(TypeHandle) { STANDARD_VM_CHECK; @@ -3550,6 +3560,8 @@ ClassLoader::LoadTypeHandleForTypeKey_Body( EX_TRY { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeHandleForTypeKey_Body / DoIncrementalLoad"); + PendingTypeLoadHolder ptlh(pLoadingEntry); TRIGGERS_TYPELOAD(); diff --git a/src/coreclr/vm/common.h b/src/coreclr/vm/common.h index 6ebe0205951b8..77d50fd06e699 100644 --- a/src/coreclr/vm/common.h +++ b/src/coreclr/vm/common.h @@ -393,6 +393,60 @@ extern DummyGlobalContract ___contract; void LogErrorToHost(const char* format, ...); +int64_t GetPreciseTickCount(); + +class InstrumentedMethod +{ +public: + class Execution + { + private: + InstrumentedMethod *_instrumentedMethod; + int64_t _startTicks; + + public: + Execution(InstrumentedMethod *method) + : _instrumentedMethod(method) + { +#ifndef DACCESS_COMPILE + _startTicks = GetPreciseTickCount(); +#endif + } + + ~Execution() + { +#ifndef DACCESS_COMPILE + _instrumentedMethod->Add(GetPreciseTickCount() - _startTicks); +#endif + } + }; + +private: + static InstrumentedMethod *s_list; + + const char *_methodName; + int64_t _count; + int64_t _ticks; + InstrumentedMethod *_next; + +public: + InstrumentedMethod(const char *methodName); + + static void DumpAllTiming(); + void Add(int64_t ticks); + +private: + void DumpTiming(); +}; + +#ifndef DACCESS_COMPILE +#define INSTRUMENTED_METHOD(name) \ + static InstrumentedMethod s_instrumentedMethod(name); \ + InstrumentedMethod::Execution methodExecution(&s_instrumentedMethod); +#else +#define INSTRUMENTED_METHOD(name) +#endif + #endif // !_common_h_ diff --git a/src/coreclr/vm/corhost.cpp b/src/coreclr/vm/corhost.cpp index 149b39078d97c..b98eb54e322d8 100644 --- a/src/coreclr/vm/corhost.cpp +++ b/src/coreclr/vm/corhost.cpp @@ -837,9 +837,9 @@ STDMETHODIMP CorHost2::UnloadAppDomain(DWORD dwDomainId, BOOL fWaitUntilDone) return UnloadAppDomain2(dwDomainId, fWaitUntilDone, nullptr); } -void DumpTypeLoadTimingInfo(); void DumpAssemblyLoadTimingInfo(); -void DumpMetadataTimingInfo(); +void DumpTypeLoadTimingInfo(); +void DumpInstrumentedMethodTimingInfo(); void FlushTimingInfo(); STDMETHODIMP CorHost2::UnloadAppDomain2(DWORD dwDomainId, BOOL fWaitUntilDone, int *pLatchedExitCode) @@ -878,8 +878,7 @@ STDMETHODIMP CorHost2::UnloadAppDomain2(DWORD dwDomainId, BOOL fWaitUntilDone, i { // Stop coreclr on unload. DumpTypeLoadTimingInfo(); - DumpMetadataTimingInfo(); - DumpAssemblyLoadTimingInfo(); + DumpInstrumentedMethodTimingInfo(); FlushTimingInfo(); EEShutDown(FALSE); diff --git a/src/coreclr/vm/methodtablebuilder.cpp b/src/coreclr/vm/methodtablebuilder.cpp index e83c5f2386511..e15ddb26a09a6 100644 --- a/src/coreclr/vm/methodtablebuilder.cpp +++ b/src/coreclr/vm/methodtablebuilder.cpp @@ -21,6 +21,110 @@ #include "customattribute.h" #include "typestring.h" +static volatile HANDLE LogFileHandle = INVALID_HANDLE_VALUE; +static volatile int64_t TimerFrequency = 0; + +void DumpInstrumentedMethodTimingInfo() +{ + InstrumentedMethod::DumpAllTiming(); +} + +int64_t GetPreciseTickCount() +{ + int64_t result; + QueryPerformanceCounter((LARGE_INTEGER *)&result); + return result; +} + +void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount) +{ + static long timingCallCount = 0; + static const int BufferSize = 1024; + static char buffer[BufferSize]; + static const char *TimingInfoFileName = +#ifdef TARGET_WINDOWS + "\\" +#else + "/" +#endif + "timing-info.txt"; + + if (LogFileHandle == INVALID_HANDLE_VALUE) + { + QueryPerformanceFrequency((LARGE_INTEGER *)&TimerFrequency); + GetCurrentDirectoryA(BufferSize, buffer); + strcat_s(buffer, BufferSize, TimingInfoFileName); + fputs("Output file: ", stdout); + puts(buffer); + + LogFileHandle = CreateFileA(buffer, + GENERIC_READ | GENERIC_WRITE, + 0, + NULL, + CREATE_ALWAYS, + FILE_ATTRIBUTE_NORMAL, + NULL); + + const char *titleLine = "CALLS/INDEX | THREAD | SECS | ACTION\n"; + WriteFile(LogFileHandle, titleLine, (DWORD)strlen(titleLine), nullptr, nullptr); + fputs(titleLine, stdout); + } + + snprintf(buffer, sizeof(buffer), "%11lld | %8x | %12.9f | %s\n", callCount, threadID, tickCount / (double)TimerFrequency, action); + fputs(buffer, stdout); + WriteFile(LogFileHandle, buffer, (DWORD)strlen(buffer), nullptr, nullptr); +} + +void FlushTimingInfo() +{ + if (LogFileHandle != INVALID_HANDLE_VALUE) + { + FlushFileBuffers(LogFileHandle); + CloseHandle(LogFileHandle); + LogFileHandle = INVALID_HANDLE_VALUE; + } +} + +InstrumentedMethod *InstrumentedMethod::s_list = nullptr; + +InstrumentedMethod::InstrumentedMethod(const char *methodName) +{ + _methodName = methodName; + _count = 0; + _ticks = 0; + _next = InterlockedExchangeT(&s_list, this); +} + +void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount); + +void InstrumentedMethod::DumpAllTiming() +{ + int64_t sumCount = 0; + int64_t sumTicks = 0; + + for (InstrumentedMethod *list = s_list; list != nullptr; list = list->_next) + { + list->DumpTiming(); + sumCount += list->_count; + sumTicks += list->_ticks; + } + + DumpTimingInfo("InstrumentedMethod", 0, sumCount, sumTicks); +} + +void InstrumentedMethod::DumpTiming() +{ +#if !defined(DACCESS_COMPILE) + DumpTimingInfo(_methodName, 0, _count, _ticks); +#endif +} + +void InstrumentedMethod::Add(int64_t ticks) +{ + InterlockedIncrement64(&_count); + InterlockedAdd64(&_ticks, ticks); +} + //******************************************************************************* // Helper functions to sort GCdescs by offset (decending order) int __cdecl compareCGCDescSeries(const void *arg1, const void *arg2) @@ -1253,6 +1357,8 @@ MethodTableBuilder::BuildMethodTableThrowing( SigPointer parentInst, WORD cBuildingInterfaceList) { + INSTRUMENTED_METHOD("MethodTableBuilder::BuildMethodTableThrowing"); + CONTRACTL { STANDARD_VM_CHECK; @@ -12372,6 +12478,8 @@ ClassLoader::CreateTypeHandleForTypeDefThrowing( Instantiation inst, AllocMemTracker * pamTracker) { + INSTRUMENTED_METHOD("ClassLoader::CreateTypeHandleForTypeDefThrowing"); + int64_t startTicks = GetPreciseTickCount(); CONTRACT(TypeHandle) From 64d2074634246e608a4a43ab26e581aecdc48f58 Mon Sep 17 00:00:00 2001 From: Tomas Rylek Date: Mon, 27 Nov 2023 20:18:34 +0100 Subject: [PATCH 5/7] More instrumentation and sorting of the output method list --- src/coreclr/vm/class.cpp | 10 ++++++- src/coreclr/vm/clsload.cpp | 11 +++++++ src/coreclr/vm/common.h | 2 +- src/coreclr/vm/methodtablebuilder.cpp | 42 ++++++++++++++++++++------- 4 files changed, 53 insertions(+), 12 deletions(-) diff --git a/src/coreclr/vm/class.cpp b/src/coreclr/vm/class.cpp index 5974fb38fc96d..7ba08c7d35c1c 100644 --- a/src/coreclr/vm/class.cpp +++ b/src/coreclr/vm/class.cpp @@ -1060,6 +1060,8 @@ ClassLoader::LoadExactParentAndInterfacesTransitively(MethodTable *pMT) if (pParentMT != NULL && pParentMT->HasInstantiation()) { + INSTRUMENTED_METHOD("ClassLoader::LoadExactParentAndInterfacesTransitively / LoadTypeDefOrRefOrSpecThrowing"); + // Fill in exact parent if it's instantiated mdToken crExtends; IfFailThrow(pInternalImport->GetTypeDefProps( @@ -1090,12 +1092,15 @@ ClassLoader::LoadExactParentAndInterfacesTransitively(MethodTable *pMT) if (pParentMT != NULL) { + INSTRUMENTED_METHOD("ClassLoader::LoadExactParentAndInterfacesTransitively / EnsureLoaded"); EnsureLoaded(pParentMT, CLASS_LOAD_EXACTPARENTS); } if (pParentMT != NULL && pParentMT->HasPerInstInfo()) { + INSTRUMENTED_METHOD("ClassLoader::LoadExactParentAndInterfacesTransitively / CopyDictionaryPointers"); + // Copy down all inherited dictionary pointers which we // could not embed. DWORD nDicts = pParentMT->GetNumDicts(); @@ -1108,7 +1113,10 @@ ClassLoader::LoadExactParentAndInterfacesTransitively(MethodTable *pMT) } } - MethodTableBuilder::LoadExactInterfaceMap(pMT); + { + INSTRUMENTED_METHOD("ClassLoader::LoadExactParentAndInterfacesTransitively / LoadExactInterfaceMap"); + MethodTableBuilder::LoadExactInterfaceMap(pMT); + } #ifdef _DEBUG if (g_pConfig->ShouldDumpOnClassLoad(pMT->GetDebugClassName())) diff --git a/src/coreclr/vm/clsload.cpp b/src/coreclr/vm/clsload.cpp index 1b86a40050b73..b810031e2a489 100644 --- a/src/coreclr/vm/clsload.cpp +++ b/src/coreclr/vm/clsload.cpp @@ -2057,6 +2057,8 @@ TypeHandle ClassLoader::LoadTypeDefOrRefOrSpecThrowing(Module *pModule, if (TypeFromToken(typeDefOrRefOrSpec) == mdtTypeSpec) { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefOrSpecThrowing / mdTypeSpec"); + ULONG cSig; PCCOR_SIGNATURE pSig; @@ -2083,6 +2085,8 @@ TypeHandle ClassLoader::LoadTypeDefOrRefOrSpecThrowing(Module *pModule, } else { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefOrSpecThrowing / LoadTypeDefOrRefThrowing"); + RETURN (LoadTypeDefOrRefThrowing(pModule, typeDefOrRefOrSpec, fNotFoundAction, fUninstantiated, @@ -2289,6 +2293,7 @@ TypeHandle ClassLoader::LoadTypeDefOrRefThrowing(ModuleBase *pModule, mdToken tokenNotToLoad, ClassLoadLevel level) { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefThrowing"); CONTRACT(TypeHandle) { @@ -2358,6 +2363,8 @@ TypeHandle ClassLoader::LoadTypeDefOrRefThrowing(ModuleBase *pModule, else if (tokType == mdtTypeRef) { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefThrowing / TypeRef"); + BOOL fNoResolutionScope; Module *pFoundModule = Assembly::FindModuleByTypeRef(pModule, typeDefOrRef, tokenNotToLoad==tdAllTypes ? @@ -2384,6 +2391,8 @@ TypeHandle ClassLoader::LoadTypeDefOrRefThrowing(ModuleBase *pModule, { if (fNoResolutionScope && pFoundModule->IsFullModule()) { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefThrowing / LoadTypeByNameThrowing"); + // Everett C++ compiler can generate a TypeRef with RS=0 // without respective TypeDef for unmanaged valuetypes, // referenced only by pointers to them, @@ -2403,6 +2412,8 @@ TypeHandle ClassLoader::LoadTypeDefOrRefThrowing(ModuleBase *pModule, } else { + INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefThrowing / LoadTypeHandleThrowIfFailed"); + NameHandle nameHandle(pModule, typeDefOrRef); nameHandle.SetName(pszNameSpace, pszClassName); nameHandle.SetTokenNotToLoad(tokenNotToLoad); diff --git a/src/coreclr/vm/common.h b/src/coreclr/vm/common.h index 77d50fd06e699..bb75fa6ddd87c 100644 --- a/src/coreclr/vm/common.h +++ b/src/coreclr/vm/common.h @@ -436,7 +436,7 @@ class InstrumentedMethod void Add(int64_t ticks); private: - void DumpTiming(); + void DumpTiming() const; }; #ifndef DACCESS_COMPILE diff --git a/src/coreclr/vm/methodtablebuilder.cpp b/src/coreclr/vm/methodtablebuilder.cpp index e15ddb26a09a6..9dc58b1a20ec6 100644 --- a/src/coreclr/vm/methodtablebuilder.cpp +++ b/src/coreclr/vm/methodtablebuilder.cpp @@ -99,20 +99,32 @@ void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, in void InstrumentedMethod::DumpAllTiming() { - int64_t sumCount = 0; - int64_t sumTicks = 0; - - for (InstrumentedMethod *list = s_list; list != nullptr; list = list->_next) + const InstrumentedMethod *minMethod = nullptr; + const InstrumentedMethod *nextMethod; + do { - list->DumpTiming(); - sumCount += list->_count; - sumTicks += list->_ticks; + nextMethod = nullptr; + for (InstrumentedMethod *list = s_list; list != nullptr; list = list->_next) + { + if (minMethod != nullptr && strcmp(list->_methodName, minMethod->_methodName) <= 0) + { + continue; + } + if (nextMethod == nullptr || strcmp(list->_methodName, nextMethod->_methodName) < 0) + { + nextMethod = list; + } + } + if (nextMethod != nullptr) + { + nextMethod->DumpTiming(); + minMethod = nextMethod; + } } - - DumpTimingInfo("InstrumentedMethod", 0, sumCount, sumTicks); + while (nextMethod != nullptr); } -void InstrumentedMethod::DumpTiming() +void InstrumentedMethod::DumpTiming() const { #if !defined(DACCESS_COMPILE) DumpTimingInfo(_methodName, 0, _count, _ticks); @@ -9379,6 +9391,8 @@ bool InstantiationIsAllTypeVariables(const Instantiation &inst) void MethodTableBuilder::LoadExactInterfaceMap(MethodTable *pMT) { + INSTRUMENTED_METHOD("MethodTableBuilder::LoadExactInterfaceMap"); + CONTRACTL { STANDARD_VM_CHECK; @@ -9445,6 +9459,8 @@ MethodTableBuilder::LoadExactInterfaceMap(MethodTable *pMT) DWORD nAssigned = 0; do { + INSTRUMENTED_METHOD("MethodTableBuilder::LoadExactInterfaceMap / do-while retry"); + nAssigned = 0; retry = false; duplicates = false; @@ -9459,6 +9475,8 @@ MethodTableBuilder::LoadExactInterfaceMap(MethodTable *pMT) InterfaceImplEnum ie(pMT->GetModule(), pMT->GetCl(), NULL); while ((hr = ie.Next()) == S_OK) { + INSTRUMENTED_METHOD("MethodTableBuilder::LoadExactInterfaceMap / do-while retry / LoadTypeDefOrRefOrSpecThrowing"); + MethodTable *pNewIntfMT = ClassLoader::LoadTypeDefOrRefOrSpecThrowing(pMT->GetModule(), ie.CurrentToken(), &typeContext, @@ -9484,6 +9502,8 @@ MethodTableBuilder::LoadExactInterfaceMap(MethodTable *pMT) MethodTable *pItfPossiblyApprox = intIt.GetInterfaceApprox(); if (uninstGenericCase && pItfPossiblyApprox->HasInstantiation() && pItfPossiblyApprox->ContainsGenericVariables()) { + INSTRUMENTED_METHOD("MethodTableBuilder::LoadExactInterfaceMap / HasInstantiation && ContainsGenericVariables"); + // We allow a limited set of interface generic shapes with type variables. In particular, we require the // instantiations to be exactly simple type variables, and to have a relatively small number of generic arguments // so that the fallback instantiating logic works efficiently @@ -9535,6 +9555,8 @@ MethodTableBuilder::LoadExactInterfaceMap(MethodTable *pMT) CONSISTENCY_CHECK(duplicates || (nAssigned == pMT->GetNumInterfaces())); if (duplicates) { + INSTRUMENTED_METHOD("MethodTableBuilder::LoadExactInterfaceMap / duplicates"); + //#LoadExactInterfaceMap_Algorithm2 // Exact interface instantiation loading TECHNIQUE 2 - The exact instantiation has caused some duplicates to // appear in the interface map! This may not be an error: if the duplicates were ones that arose because of From b813af4190a050965798d99a49582e1daae410b5 Mon Sep 17 00:00:00 2001 From: Tomas Rylek Date: Sat, 2 Dec 2023 23:10:52 +0100 Subject: [PATCH 6/7] Looging of NativeImage loading --- src/coreclr/vm/methodtablebuilder.cpp | 34 +++++++++++++++++---------- src/coreclr/vm/nativeimage.cpp | 10 ++++++++ 2 files changed, 31 insertions(+), 13 deletions(-) diff --git a/src/coreclr/vm/methodtablebuilder.cpp b/src/coreclr/vm/methodtablebuilder.cpp index 9dc58b1a20ec6..57c7d122dfb9f 100644 --- a/src/coreclr/vm/methodtablebuilder.cpp +++ b/src/coreclr/vm/methodtablebuilder.cpp @@ -12393,19 +12393,6 @@ const int RING_BUFFER_SIZE = 65536; static TypeLoadTiming TypeLoadTimingRingBuffer[RING_BUFFER_SIZE]; static volatile long TypeLoadRingBufferIndex = 0; -void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks) -{ - InterlockedAdd64(&TypeLoadTickCount, ticks); - InterlockedIncrement64(&TypeLoadCallCount); - long timingIndex = InterlockedIncrement(&TypeLoadRingBufferIndex) - 1; - if (timingIndex >= 0 && timingIndex < RING_BUFFER_SIZE) - { - TypeLoadTimingRingBuffer[timingIndex].Thread = GetCurrentThreadId(); - TypeLoadTimingRingBuffer[timingIndex].Ticks = ticks; - TypeLoadTimingRingBuffer[timingIndex].Type = type; - } -} - static const int TypeNameBufferSize = 65536; static char TypeNameBuffer[TypeNameBufferSize]; @@ -12443,6 +12430,27 @@ char *FormatTypeName(char *typeBuffer, TypeHandle type) return typeBuffer; } +void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks) +{ + InterlockedAdd64(&TypeLoadTickCount, ticks); + InterlockedIncrement64(&TypeLoadCallCount); + long timingIndex = InterlockedIncrement(&TypeLoadRingBufferIndex) - 1; + if (timingIndex >= 0 && timingIndex < RING_BUFFER_SIZE) + { + TypeLoadTimingRingBuffer[timingIndex].Thread = GetCurrentThreadId(); + TypeLoadTimingRingBuffer[timingIndex].Ticks = ticks; + TypeLoadTimingRingBuffer[timingIndex].Type = type; + } + /* + char stackBuffer[16384]; + FormatTypeName(stackBuffer, type); + if (!strcmp(stackBuffer, "System.Numerics.IAdditiveIdentity`2")) + { + DebugBreak(); + } + */ +} + void DumpTypeLoadTimingInfo() { HashMap threadMap; diff --git a/src/coreclr/vm/nativeimage.cpp b/src/coreclr/vm/nativeimage.cpp index 49f797f896254..11f721e9f7101 100644 --- a/src/coreclr/vm/nativeimage.cpp +++ b/src/coreclr/vm/nativeimage.cpp @@ -62,6 +62,8 @@ NativeImage::NativeImage(AssemblyBinder *pAssemblyBinder, PEImageLayout *pImageL void NativeImage::Initialize(READYTORUN_HEADER *pHeader, LoaderAllocator *pLoaderAllocator, AllocMemTracker *pamTracker) { + INSTRUMENTED_METHOD("NativeImage::Initialize"); + LoaderHeap *pHeap = pLoaderAllocator->GetHighFrequencyHeap(); m_pReadyToRunInfo = new ReadyToRunInfo(/*pModule*/ NULL, pLoaderAllocator, m_pImageLayout, pHeader, this, pamTracker); @@ -115,6 +117,8 @@ NativeImage *NativeImage::Open( LoaderAllocator *pLoaderAllocator, /* out */ bool *isNewNativeImage) { + INSTRUMENTED_METHOD("NativeImage::Open"); + STANDARD_VM_CONTRACT; NativeImage *pExistingImage = AppDomain::GetCurrentDomain()->GetNativeImage(nativeImageFileName); @@ -263,6 +267,8 @@ NativeImage *NativeImage::Open( #ifndef DACCESS_COMPILE Assembly *NativeImage::LoadManifestAssembly(uint32_t rowid, DomainAssembly *pParentAssembly) { + INSTRUMENTED_METHOD("NativeImage::LoadManifestAssembly"); + STANDARD_VM_CONTRACT; AssemblySpec spec; @@ -274,6 +280,8 @@ Assembly *NativeImage::LoadManifestAssembly(uint32_t rowid, DomainAssembly *pPar #ifndef DACCESS_COMPILE PTR_READYTORUN_CORE_HEADER NativeImage::GetComponentAssemblyHeader(LPCUTF8 simpleName) { + INSTRUMENTED_METHOD("NativeImage::GetComponentAssemblyHeader"); + STANDARD_VM_CONTRACT; const AssemblyNameIndex *assemblyNameIndex = m_assemblySimpleNameToIndexMap.LookupPtr(simpleName); @@ -291,6 +299,8 @@ PTR_READYTORUN_CORE_HEADER NativeImage::GetComponentAssemblyHeader(LPCUTF8 simpl #ifndef DACCESS_COMPILE IMDInternalImport *NativeImage::LoadManifestMetadata() { + INSTRUMENTED_METHOD("NativeImage::LoadManifestMetadata"); + STANDARD_VM_CONTRACT; IMAGE_DATA_DIRECTORY *pMeta = m_pReadyToRunInfo->FindSection(ReadyToRunSectionType::ManifestMetadata); From 278114e5f56187a1ef83351f25b321cc8aed5b12 Mon Sep 17 00:00:00 2001 From: Tomas Rylek Date: Sun, 3 Dec 2023 22:27:32 +0100 Subject: [PATCH 7/7] Add support for inclusive / exclusive time measurement --- src/coreclr/vm/clsload.cpp | 17 +++- src/coreclr/vm/methodtablebuilder.cpp | 112 +++++++++----------------- 2 files changed, 52 insertions(+), 77 deletions(-) diff --git a/src/coreclr/vm/clsload.cpp b/src/coreclr/vm/clsload.cpp index b810031e2a489..89d9a14021247 100644 --- a/src/coreclr/vm/clsload.cpp +++ b/src/coreclr/vm/clsload.cpp @@ -3250,7 +3250,9 @@ static void PushFinalLevels(TypeHandle typeHnd, ClassLoadLevel targetLevel, cons } } -void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks); +void RecordTypeLoadTime(const TypeHandle& type, int64_t inclusiveTicks, int64_t subtreeTicks); + +thread_local int64_t *PendingTypeLoad = nullptr; // TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, @@ -3260,6 +3262,9 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, { INSTRUMENTED_METHOD("ClassLoader::LoadTypeHandleForTypeKey"); int64_t startTicks = GetPreciseTickCount(); + int64_t *parentTypeLoad = PendingTypeLoad; + int64_t subtreeTypeLoadTicks = 0; + PendingTypeLoad = &subtreeTypeLoadTicks; CONTRACTL { @@ -3308,7 +3313,15 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey, } #endif - RecordTypeLoadTime(typeHnd, GetPreciseTickCount() - startTicks); + int64_t inclusiveTicks = GetPreciseTickCount() - startTicks; + RecordTypeLoadTime(typeHnd, inclusiveTicks, subtreeTypeLoadTicks); + + if (parentTypeLoad != nullptr) + { + *parentTypeLoad += inclusiveTicks; + } + + PendingTypeLoad = parentTypeLoad; return typeHnd; } diff --git a/src/coreclr/vm/methodtablebuilder.cpp b/src/coreclr/vm/methodtablebuilder.cpp index 57c7d122dfb9f..ad012b873672e 100644 --- a/src/coreclr/vm/methodtablebuilder.cpp +++ b/src/coreclr/vm/methodtablebuilder.cpp @@ -36,7 +36,7 @@ int64_t GetPreciseTickCount() return result; } -void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount) +void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t inclusiveTickCount, int64_t subtreeTickCount = 0) { static long timingCallCount = 0; static const int BufferSize = 1024; @@ -65,12 +65,21 @@ void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, in FILE_ATTRIBUTE_NORMAL, NULL); - const char *titleLine = "CALLS/INDEX | THREAD | SECS | ACTION\n"; + const char *titleLine = "CALLS/INDEX | THREAD | INCLUSIVE SECS | EXCLUSIVE SECS | SUBTREE SECS | EXCLUSIVE % | SUBTREE % | ACTION\n"; WriteFile(LogFileHandle, titleLine, (DWORD)strlen(titleLine), nullptr, nullptr); fputs(titleLine, stdout); } - - snprintf(buffer, sizeof(buffer), "%11lld | %8x | %12.9f | %s\n", callCount, threadID, tickCount / (double)TimerFrequency, action); + + int64_t exclusiveTickCount = inclusiveTickCount - subtreeTickCount; + double inclusiveTicksPercentageFactor = 100.0 / (inclusiveTickCount ? inclusiveTickCount : 1); + snprintf(buffer, sizeof(buffer), "%11lld | %8x | %14.9f | %14.9f | %14.9f | %11.2f | %9.2f | %s\n", + callCount, threadID, + inclusiveTickCount / (double)TimerFrequency, + exclusiveTickCount / (double)TimerFrequency, + subtreeTickCount / (double)TimerFrequency, + exclusiveTickCount * inclusiveTicksPercentageFactor, + subtreeTickCount * inclusiveTicksPercentageFactor, + action); fputs(buffer, stdout); WriteFile(LogFileHandle, buffer, (DWORD)strlen(buffer), nullptr, nullptr); } @@ -95,8 +104,6 @@ InstrumentedMethod::InstrumentedMethod(const char *methodName) _next = InterlockedExchangeT(&s_list, this); } -void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount); - void InstrumentedMethod::DumpAllTiming() { const InstrumentedMethod *minMethod = nullptr; @@ -12376,16 +12383,13 @@ BOOL HasLayoutMetadata(Assembly* pAssembly, IMDInternalImport* pInternalImport, } int64_t GetPreciseTickCount(); -void DumpTimingInfo(const char *action, uint32_t threadID, int64_t callCount, int64_t tickCount); - -static int64_t TypeLoadCallCount = 0; -static int64_t TypeLoadTickCount = 0; struct TypeLoadTiming { - uint32_t Thread; - int64_t Ticks; + int64_t InclusiveTicks; + int64_t SubtreeTicks; TypeHandle Type; + uint32_t Thread; }; const int RING_BUFFER_SIZE = 65536; @@ -12393,62 +12397,16 @@ const int RING_BUFFER_SIZE = 65536; static TypeLoadTiming TypeLoadTimingRingBuffer[RING_BUFFER_SIZE]; static volatile long TypeLoadRingBufferIndex = 0; -static const int TypeNameBufferSize = 65536; -static char TypeNameBuffer[TypeNameBufferSize]; - -char *FormatTypeName(char *typeBuffer, TypeHandle type) +void RecordTypeLoadTime(const TypeHandle& type, int64_t inclusiveTicks, int64_t subtreeTicks) { - if (type.IsTypeDesc()) - { - SString buffer; - type.AsTypeDesc()->GetName(buffer); - strcpy(typeBuffer, buffer.GetUTF8()); - typeBuffer += strlen(typeBuffer); - return typeBuffer; - } - - MethodTable *pMT = type.AsMethodTable(); - { - SString buffer; - pMT->_GetFullyQualifiedNameForClassNestedAware(buffer); - strcpy(typeBuffer, buffer.GetUTF8()); - } - typeBuffer += strlen(typeBuffer); - - Instantiation instantiation = pMT->GetInstantiation(); - if (!instantiation.IsEmpty()) - { - for (DWORD argIndex = 0; argIndex < instantiation.GetNumArgs(); argIndex++) - { - strcpy(typeBuffer, argIndex == 0 ? "<" : ", "); - typeBuffer += strlen(typeBuffer); - typeBuffer = FormatTypeName(typeBuffer, instantiation[argIndex]); - } - *typeBuffer++ = '>'; - *typeBuffer = 0; - } - return typeBuffer; -} - -void RecordTypeLoadTime(const TypeHandle& type, int64_t ticks) -{ - InterlockedAdd64(&TypeLoadTickCount, ticks); - InterlockedIncrement64(&TypeLoadCallCount); long timingIndex = InterlockedIncrement(&TypeLoadRingBufferIndex) - 1; if (timingIndex >= 0 && timingIndex < RING_BUFFER_SIZE) { TypeLoadTimingRingBuffer[timingIndex].Thread = GetCurrentThreadId(); - TypeLoadTimingRingBuffer[timingIndex].Ticks = ticks; + TypeLoadTimingRingBuffer[timingIndex].InclusiveTicks = inclusiveTicks; + TypeLoadTimingRingBuffer[timingIndex].SubtreeTicks = subtreeTicks; TypeLoadTimingRingBuffer[timingIndex].Type = type; } - /* - char stackBuffer[16384]; - FormatTypeName(stackBuffer, type); - if (!strcmp(stackBuffer, "System.Numerics.IAdditiveIdentity`2")) - { - DebugBreak(); - } - */ } void DumpTypeLoadTimingInfo() @@ -12459,40 +12417,44 @@ void DumpTypeLoadTimingInfo() for (int32_t ringBufferIndex = 0; ringBufferIndex < TypeLoadRingBufferIndex; ringBufferIndex++) { const TypeLoadTiming& timing = TypeLoadTimingRingBuffer[ringBufferIndex]; - char *typeBuffer = FormatTypeName(TypeNameBuffer, timing.Type); - - if (typeBuffer >= TypeNameBuffer + TypeNameBufferSize) - { - CrashDumpAndTerminateProcess(STATUS_STACK_BUFFER_OVERRUN); - } - - DumpTimingInfo(TypeNameBuffer, timing.Thread, ringBufferIndex, timing.Ticks); + SString typeName; + timing.Type.GetName(typeName); + DumpTimingInfo(typeName.GetUTF8(), timing.Thread, ringBufferIndex, timing.InclusiveTicks, timing.SubtreeTicks); if (threadMap.LookupValue(timing.Thread, timing.Thread) == INVALIDENTRY) { threadMap.InsertValue(timing.Thread, timing.Thread); } } + int32_t totalCount = 0; + int64_t totalInclusiveTicks = 0; + int64_t totalSubtreeTicks = 0; for (HashMap::Iterator it = threadMap.begin(); !it.end(); ++it) { uint32_t threadID = (uint32_t)it.GetKey(); - int32_t sumCount = 0; - int64_t sumTicks = 0; + int32_t threadCount = 0; + int64_t threadInclusiveTicks = 0; + int64_t threadSubtreeTicks = 0; for (int32_t ringBufferIndex = 0; ringBufferIndex < TypeLoadRingBufferIndex; ringBufferIndex++) { const TypeLoadTiming& timing = TypeLoadTimingRingBuffer[ringBufferIndex]; if (timing.Thread == threadID) { - sumTicks += timing.Ticks; - sumCount++; + threadInclusiveTicks += timing.InclusiveTicks; + threadSubtreeTicks += timing.SubtreeTicks; + threadCount++; } } char buffer[100]; sprintf(buffer, "LoadTypeHandleForTypeKey @ %08x", threadID); - DumpTimingInfo(buffer, threadID, sumCount, sumTicks); + DumpTimingInfo(buffer, threadID, threadCount, threadInclusiveTicks, threadSubtreeTicks); + + totalCount += threadCount; + totalInclusiveTicks += threadInclusiveTicks; + totalSubtreeTicks += threadSubtreeTicks; } - DumpTimingInfo("LoadTypeHandleForTypeKey", GetCurrentThreadId(), TypeLoadCallCount, TypeLoadTickCount); + DumpTimingInfo("LoadTypeHandleForTypeKey", GetCurrentThreadId(), totalCount, totalInclusiveTicks, totalSubtreeTicks); } //---------------------------------------------------------------------------------------