[NO-MERGE] CoreCLR runtime instrumentation for measuring type load performance

src/coreclr/md/runtime/mdinternalro.cpp

@@ -798,7 +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.
 {
-
     return FindMethodDefUsingCompare(classdef,
                                      szName,
                                      pvSigBlob,
@@ -1227,7 +1226,6 @@ HRESULT MDInternalRO::GetItemGuid(      // return hresult
     mdToken     tkObj,                  // given item
     CLSID       *pGuid)
 {
-
     HRESULT     hr;                     // A result.
     const BYTE  *pBlob = NULL;          // Blob with dispid.
     ULONG       cbBlob;                 // Length of blob.

src/coreclr/vm/appdomain.cpp

@@ -2562,6 +2562,8 @@ CHECK AppDomain::CheckCanExecuteManagedCode(MethodDesc* pMD)
 void AppDomain::LoadDomainAssembly(DomainAssembly *pFile,
                                FileLoadLevel targetLevel)
 {
+    INSTRUMENTED_METHOD("AppDomain::LoadDomainAssembly");
+
     CONTRACTL
     {
         if (FORBIDGC_LOADER_USE_ENABLED()) NOTHROW; else THROWS;

src/coreclr/vm/class.cpp

@@ -1043,6 +1043,8 @@ EEClass::CheckVarianceInSig(
 void
 ClassLoader::LoadExactParentAndInterfacesTransitively(MethodTable *pMT)
 {
+    INSTRUMENTED_METHOD("ClassLoader::LoadExactParentAndInterfacesTransitively");
+
     CONTRACTL
     {
         STANDARD_VM_CHECK;
@@ -1058,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(
@@ -1088,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();
@@ -1106,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()))
@@ -1200,6 +1210,8 @@ namespace
 /*static*/
 void ClassLoader::LoadExactParents(MethodTable* pMT)
 {
+    INSTRUMENTED_METHOD("ClassLoader::LoadExactParents");
+
     CONTRACT_VOID
     {
         STANDARD_VM_CHECK;

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;
@@ -2055,6 +2057,8 @@ TypeHandle ClassLoader::LoadTypeDefOrRefOrSpecThrowing(Module *pModule,
 
     if (TypeFromToken(typeDefOrRefOrSpec) == mdtTypeSpec)
     {
+        INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefOrSpecThrowing / mdTypeSpec");
+
         ULONG cSig;
         PCCOR_SIGNATURE pSig;
 
@@ -2081,6 +2085,8 @@ TypeHandle ClassLoader::LoadTypeDefOrRefOrSpecThrowing(Module *pModule,
     }
     else
     {
+        INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefOrSpecThrowing / LoadTypeDefOrRefThrowing");
+
         RETURN (LoadTypeDefOrRefThrowing(pModule, typeDefOrRefOrSpec,
                                          fNotFoundAction,
                                          fUninstantiated,
@@ -2287,6 +2293,7 @@ TypeHandle ClassLoader::LoadTypeDefOrRefThrowing(ModuleBase *pModule,
                                                  mdToken tokenNotToLoad,
                                                  ClassLoadLevel level)
 {
+    INSTRUMENTED_METHOD("ClassLoader::LoadTypeDefOrRefThrowing");
 
     CONTRACT(TypeHandle)
     {
@@ -2356,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 ?
@@ -2382,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,
@@ -2401,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);
@@ -2846,6 +2859,8 @@ ClassLoader::LoadApproxParentThrowing(
 /*static*/
 TypeHandle ClassLoader::DoIncrementalLoad(TypeKey *pTypeKey, TypeHandle typeHnd, ClassLoadLevel currentLevel)
 {
+    INSTRUMENTED_METHOD("ClassLoader::DoIncrementalLoad");
+
     CONTRACTL
     {
         STANDARD_VM_CHECK;
@@ -2873,6 +2888,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 +2911,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 +2925,7 @@ TypeHandle ClassLoader::DoIncrementalLoad(TypeKey *pTypeKey, TypeHandle typeHnd,
 
     if (typeHnd.GetLoadLevel() >= CLASS_LOAD_EXACTPARENTS)
     {
+        INSTRUMENTED_METHOD("ClassLoader::DoIncrementalLoad / Notify");
         Notify(typeHnd);
     }
 
@@ -3231,14 +3250,22 @@ static void PushFinalLevels(TypeHandle typeHnd, ClassLoadLevel targetLevel, cons
     }
 }
 
+void RecordTypeLoadTime(const TypeHandle& type, int64_t inclusiveTicks, int64_t subtreeTicks);
+
+thread_local int64_t *PendingTypeLoad = nullptr;
 
 //
 TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey,
                                                  TypeHandle typeHnd,
                                                  ClassLoadLevel targetLevel/*=CLASS_LOADED*/,
                                                  const InstantiationContext *pInstContext/*=NULL*/)
 {
-
+    INSTRUMENTED_METHOD("ClassLoader::LoadTypeHandleForTypeKey");
+    int64_t startTicks = GetPreciseTickCount();
+    int64_t *parentTypeLoad = PendingTypeLoad;
+    int64_t subtreeTypeLoadTicks = 0;
+    PendingTypeLoad = &subtreeTypeLoadTicks;
+
     CONTRACTL
     {
         INSTANCE_CHECK;
@@ -3286,6 +3313,16 @@ TypeHandle ClassLoader::LoadTypeHandleForTypeKey(TypeKey *pTypeKey,
     }
 #endif
 
+    int64_t inclusiveTicks = GetPreciseTickCount() - startTicks;
+    RecordTypeLoadTime(typeHnd, inclusiveTicks, subtreeTypeLoadTicks);
+
+    if (parentTypeLoad != nullptr)
+    {
+        *parentTypeLoad += inclusiveTicks;
+    }
+
+    PendingTypeLoad = parentTypeLoad;
+
     return typeHnd;
 }
 
@@ -3379,6 +3416,8 @@ ClassLoader::LoadTypeHandleForTypeKey_Body(
     TypeHandle                        typeHnd,
     ClassLoadLevel                    targetLevel)
 {
+    INSTRUMENTED_METHOD("ClassLoader::LoadTypeHandleForTypeKey_Body");
+
     CONTRACT(TypeHandle)
     {
         STANDARD_VM_CHECK;
@@ -3545,6 +3584,8 @@ ClassLoader::LoadTypeHandleForTypeKey_Body(
 
     EX_TRY
     {
+        INSTRUMENTED_METHOD("ClassLoader::LoadTypeHandleForTypeKey_Body / DoIncrementalLoad");
+
         PendingTypeLoadHolder ptlh(pLoadingEntry);
 
         TRIGGERS_TYPELOAD();

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() const;
+};
+
+#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_
 
 

src/coreclr/vm/corhost.cpp

@@ -837,6 +837,11 @@ STDMETHODIMP CorHost2::UnloadAppDomain(DWORD dwDomainId, BOOL fWaitUntilDone)
     return UnloadAppDomain2(dwDomainId, fWaitUntilDone, nullptr);
 }
 
+void DumpAssemblyLoadTimingInfo();
+void DumpTypeLoadTimingInfo();
+void DumpInstrumentedMethodTimingInfo();
+void FlushTimingInfo();
+
 STDMETHODIMP CorHost2::UnloadAppDomain2(DWORD dwDomainId, BOOL fWaitUntilDone, int *pLatchedExitCode)
 {
     WRAPPER_NO_CONTRACT;
@@ -872,6 +877,10 @@ STDMETHODIMP CorHost2::UnloadAppDomain2(DWORD dwDomainId, BOOL fWaitUntilDone, i
         if (1 == refCount)
         {
             // Stop coreclr on unload.
+            DumpTypeLoadTimingInfo();
+            DumpInstrumentedMethodTimingInfo();
+            FlushTimingInfo();
+
             EEShutDown(FALSE);
         }
         else