Improve ENC logging. (#53695)

Fix assert in CMiniMdRW::GetTableForToken.  g_TblIndex entries for MethodImpl and NestedClass needed token values.

diff --git a/src/coreclr/gc/objecthandle.cpp b/src/coreclr/gc/objecthandle.cpp
index 208689b..1485f56 100644 (file)
--- a/src/coreclr/gc/objecthandle.cpp
+++ b/src/coreclr/gc/objecthandle.cpp
@@ -151,9 +151,9 @@ void CALLBACK UpdateDependentHandle(_UNCHECKED_OBJECTREF *pObjRef, uintptr_t *pE
     Object **pPrimaryRef = (Object **)pObjRef;
     Object **pSecondaryRef = (Object **)pExtraInfo;
 
-    LOG((LF_GC|LF_ENC, LL_INFO10000, LOG_HANDLE_OBJECT("Querying for new location of ",
+    LOG((LF_GC, LL_INFO10000, LOG_HANDLE_OBJECT("Querying for new location of ",
             pPrimaryRef, "to ", *pPrimaryRef)));
-    LOG((LF_GC|LF_ENC, LL_INFO10000, LOG_HANDLE_OBJECT(" and ",
+    LOG((LF_GC, LL_INFO10000, LOG_HANDLE_OBJECT(" and ",
             pSecondaryRef, "to ", *pSecondaryRef)));
 
 #ifdef _DEBUG
@@ -168,16 +168,16 @@ void CALLBACK UpdateDependentHandle(_UNCHECKED_OBJECTREF *pObjRef, uintptr_t *pE
 
 #ifdef _DEBUG
     if (pOldPrimary != *pPrimaryRef)
-        LOG((LF_GC|LF_ENC, LL_INFO10000,  "Updating " FMT_HANDLE "from" FMT_ADDR "to " FMT_OBJECT "\n",
+        LOG((LF_GC, LL_INFO10000,  "Updating " FMT_HANDLE "from" FMT_ADDR "to " FMT_OBJECT "\n",
              DBG_ADDR(pPrimaryRef), DBG_ADDR(pOldPrimary), DBG_ADDR(*pPrimaryRef)));
     else
-        LOG((LF_GC|LF_ENC, LL_INFO10000, "Updating " FMT_HANDLE "- " FMT_OBJECT "did not move\n",
+        LOG((LF_GC, LL_INFO10000, "Updating " FMT_HANDLE "- " FMT_OBJECT "did not move\n",
              DBG_ADDR(pPrimaryRef), DBG_ADDR(*pPrimaryRef)));
     if (pOldSecondary != *pSecondaryRef)
-        LOG((LF_GC|LF_ENC, LL_INFO10000,  "Updating " FMT_HANDLE "from" FMT_ADDR "to " FMT_OBJECT "\n",
+        LOG((LF_GC, LL_INFO10000,  "Updating " FMT_HANDLE "from" FMT_ADDR "to " FMT_OBJECT "\n",
              DBG_ADDR(pSecondaryRef), DBG_ADDR(pOldSecondary), DBG_ADDR(*pSecondaryRef)));
     else
-        LOG((LF_GC|LF_ENC, LL_INFO10000, "Updating " FMT_HANDLE "- " FMT_OBJECT "did not move\n",
+        LOG((LF_GC, LL_INFO10000, "Updating " FMT_HANDLE "- " FMT_OBJECT "did not move\n",
              DBG_ADDR(pSecondaryRef), DBG_ADDR(*pSecondaryRef)));
 #endif
 }
@@ -189,9 +189,9 @@ void CALLBACK PromoteDependentHandle(_UNCHECKED_OBJECTREF *pObjRef, uintptr_t *p
 
     Object **pPrimaryRef = (Object **)pObjRef;
     Object **pSecondaryRef = (Object **)pExtraInfo;
-    LOG((LF_GC|LF_ENC, LL_INFO1000, "Checking promotion of DependentHandle"));
-    LOG((LF_GC|LF_ENC, LL_INFO1000, LOG_HANDLE_OBJECT_CLASS("\tPrimary:\t", pObjRef, "to ", *pObjRef)));
-    LOG((LF_GC|LF_ENC, LL_INFO1000, LOG_HANDLE_OBJECT_CLASS("\tSecondary\t", pSecondaryRef, "to ", *pSecondaryRef)));
+    LOG((LF_GC, LL_INFO1000, "Checking promotion of DependentHandle\n"));
+    LOG((LF_GC, LL_INFO1000, LOG_HANDLE_OBJECT_CLASS("\tPrimary:\t", pObjRef, "to ", *pObjRef)));
+    LOG((LF_GC, LL_INFO1000, LOG_HANDLE_OBJECT_CLASS("\tSecondary\t", pSecondaryRef, "to ", *pSecondaryRef)));
 
     ScanContext *sc = (ScanContext*)lp1;
     DhContext *pDhContext = Ref_GetDependentHandleContext(sc);
@@ -200,7 +200,7 @@ void CALLBACK PromoteDependentHandle(_UNCHECKED_OBJECTREF *pObjRef, uintptr_t *p
     {
         if (!g_theGCHeap->IsPromoted(*pSecondaryRef))
         {
-            LOG((LF_GC|LF_ENC, LL_INFO10000, "\tPromoting secondary " LOG_OBJECT_CLASS(*pSecondaryRef)));
+            LOG((LF_GC, LL_INFO10000, "\tPromoting secondary " LOG_OBJECT_CLASS(*pSecondaryRef)));
             _ASSERTE(lp2);
             promote_func* callback = (promote_func*) lp2;
             callback(pSecondaryRef, (ScanContext *)lp1, 0);
@@ -227,22 +227,22 @@ void CALLBACK ClearDependentHandle(_UNCHECKED_OBJECTREF *pObjRef, uintptr_t *pEx
 
     Object **pPrimaryRef = (Object **)pObjRef;
     Object **pSecondaryRef = (Object **)pExtraInfo;
-    LOG((LF_GC|LF_ENC, LL_INFO1000, "Checking referent of DependentHandle"));
-    LOG((LF_GC|LF_ENC, LL_INFO1000, LOG_HANDLE_OBJECT_CLASS("\tPrimary:\t", pPrimaryRef, "to ", *pPrimaryRef)));
-    LOG((LF_GC|LF_ENC, LL_INFO1000, LOG_HANDLE_OBJECT_CLASS("\tSecondary\t", pSecondaryRef, "to ", *pSecondaryRef)));
+    LOG((LF_GC, LL_INFO1000, "Checking referent of DependentHandle"));
+    LOG((LF_GC, LL_INFO1000, LOG_HANDLE_OBJECT_CLASS("\tPrimary:\t", pPrimaryRef, "to ", *pPrimaryRef)));
+    LOG((LF_GC, LL_INFO1000, LOG_HANDLE_OBJECT_CLASS("\tSecondary\t", pSecondaryRef, "to ", *pSecondaryRef)));
 
     if (!g_theGCHeap->IsPromoted(*pPrimaryRef))
     {
-        LOG((LF_GC|LF_ENC, LL_INFO1000, "\tunreachable ", LOG_OBJECT_CLASS(*pPrimaryRef)));
-        LOG((LF_GC|LF_ENC, LL_INFO1000, "\tunreachable ", LOG_OBJECT_CLASS(*pSecondaryRef)));
+        LOG((LF_GC, LL_INFO1000, "\tunreachable ", LOG_OBJECT_CLASS(*pPrimaryRef)));
+        LOG((LF_GC, LL_INFO1000, "\tunreachable ", LOG_OBJECT_CLASS(*pSecondaryRef)));
         *pPrimaryRef = NULL;
         *pSecondaryRef = NULL;
     }
     else
     {
         _ASSERTE(g_theGCHeap->IsPromoted(*pSecondaryRef));
-        LOG((LF_GC|LF_ENC, LL_INFO10000, "\tPrimary is reachable " LOG_OBJECT_CLASS(*pPrimaryRef)));
-        LOG((LF_GC|LF_ENC, LL_INFO10000, "\tSecondary is reachable " LOG_OBJECT_CLASS(*pSecondaryRef)));
+        LOG((LF_GC, LL_INFO10000, "\tPrimary is reachable " LOG_OBJECT_CLASS(*pPrimaryRef)));
+        LOG((LF_GC, LL_INFO10000, "\tSecondary is reachable " LOG_OBJECT_CLASS(*pSecondaryRef)));
     }
 }
 

diff --git a/src/coreclr/inc/corhdr.h b/src/coreclr/inc/corhdr.h
index de3e95d..ecefcef 100644 (file)
--- a/src/coreclr/inc/corhdr.h
+++ b/src/coreclr/inc/corhdr.h
@@ -1498,6 +1498,7 @@ typedef enum CorTokenType
     mdtFile                 = 0x26000000,       //
     mdtExportedType         = 0x27000000,       //
     mdtManifestResource     = 0x28000000,       //
+    mdtNestedClass          = 0x29000000,       //
     mdtGenericParam         = 0x2a000000,       //
     mdtMethodSpec           = 0x2b000000,       //
     mdtGenericParamConstraint = 0x2c000000,

diff --git a/src/coreclr/md/enc/metamodelrw.cpp b/src/coreclr/md/enc/metamodelrw.cpp
index 4a849af..5f62e5f 100644 (file)
--- a/src/coreclr/md/enc/metamodelrw.cpp
+++ b/src/coreclr/md/enc/metamodelrw.cpp
@@ -264,7 +264,7 @@ const TblIndex g_TblIndex[TBL_COUNT] =
     {(ULONG) -1,        (ULONG) -1,     (ULONG) -1},        // PropertyPtr
     {(ULONG) -1,        (ULONG) -1,     mdtProperty},       // Property
     {(ULONG) -1,        (ULONG) -1,     (ULONG) -1},        // MethodSemantics
-    {(ULONG) -1,        (ULONG) -1,     (ULONG) -1},        // MethodImpl
+    {(ULONG) -1,        (ULONG) -1,     mdtMethodImpl},     // MethodImpl
     {(ULONG) -1,        (ULONG) -1,     mdtModuleRef},      // ModuleRef
     {(ULONG) -1,        (ULONG) -1,     mdtTypeSpec},       // TypeSpec
     {(ULONG) -1,        (ULONG) -1,     (ULONG) -1},        // ImplMap  <TODO>@FUTURE:  Check that these are the right entries here.</TODO>
@@ -280,7 +280,7 @@ const TblIndex g_TblIndex[TBL_COUNT] =
     {(ULONG) -1,        (ULONG) -1,     mdtFile},           // File <TODO>@FUTURE: Update with the right number.</TODO>
     {(ULONG) -1,        (ULONG) -1,     mdtExportedType},   // ExportedType <TODO>@FUTURE: Update with the right number.</TODO>
     {(ULONG) -1,        (ULONG) -1,     mdtManifestResource},// ManifestResource <TODO>@FUTURE: Update with the right number.</TODO>
-    {(ULONG) -1,        (ULONG) -1,     (ULONG) -1},        // NestedClass
+    {(ULONG) -1,        (ULONG) -1,     mdtNestedClass},    // NestedClass
     {(ULONG) -1,        (ULONG) -1,     mdtGenericParam},   // GenericParam
     {(ULONG) -1,        (ULONG) -1,     mdtMethodSpec},     // MethodSpec
     {(ULONG) -1,        (ULONG) -1,     mdtGenericParamConstraint},// GenericParamConstraint

diff --git a/src/coreclr/vm/class.cpp b/src/coreclr/vm/class.cpp
index 80a7024..17417e0 100644 (file)
--- a/src/coreclr/vm/class.cpp
+++ b/src/coreclr/vm/class.cpp
@@ -274,7 +274,7 @@ VOID EEClass::FixupFieldDescForEnC(MethodTable * pMT, EnCFieldDesc *pFD, mdField
         {
             szFieldName = "Invalid FieldDef record";
         }
-        LOG((LF_ENC, LL_INFO100, "EEClass::InitializeFieldDescForEnC %s\n", szFieldName));
+        LOG((LF_ENC, LL_INFO100, "EEClass::FixupFieldDescForEnC %08x %s\n", fieldDef, szFieldName));
     }
 #endif //LOGGING
 

diff --git a/src/coreclr/vm/encee.cpp b/src/coreclr/vm/encee.cpp
index ca9e16d..64a006f 100644 (file)
--- a/src/coreclr/vm/encee.cpp
+++ b/src/coreclr/vm/encee.cpp
@@ -46,7 +46,7 @@ EditAndContinueModule::EditAndContinueModule(Assembly *pAssembly, mdToken module
     }
     CONTRACTL_END
 
-    LOG((LF_ENC,LL_INFO100,"EACM::ctor 0x%x\n", this));
+    LOG((LF_ENC,LL_INFO100,"EACM::ctor %p\n", this));
 
     m_applyChangesCount = CorDB_DEFAULT_ENC_FUNCTION_VERSION;
 }
@@ -68,7 +68,7 @@ void EditAndContinueModule::Initialize(AllocMemTracker *pamTracker, LPCWSTR szNa
     }
     CONTRACTL_END
 
-    LOG((LF_ENC,LL_INFO100,"EACM::Initialize 0x%x\n", this));
+    LOG((LF_ENC,LL_INFO100,"EACM::Initialize %p\n", this));
     Module::Initialize(pamTracker, szName);
 }
 
@@ -76,7 +76,7 @@ void EditAndContinueModule::Initialize(AllocMemTracker *pamTracker, LPCWSTR szNa
 void EditAndContinueModule::Destruct()
 {
     LIMITED_METHOD_CONTRACT;
-    LOG((LF_ENC,LL_EVERYTHING,"EACM::Destruct 0x%x\n", this));
+    LOG((LF_ENC,LL_EVERYTHING,"EACM::Destruct %p\n", this));
 
     // Call the superclass's Destruct method...
     Module::Destruct();
@@ -211,14 +211,14 @@ HRESULT EditAndContinueModule::ApplyEditAndContinue(
     mdToken token;
     while (pIMDInternalImportENC->EnumNext(&enumENC, &token))
     {
-        STRESS_LOG3(LF_ENC, LL_INFO100, "EACM::AEAC: updated token 0x%x; type 0x%x; rid 0x%x\n", token, TypeFromToken(token), RidFromToken(token));
+        STRESS_LOG3(LF_ENC, LL_INFO100, "EACM::AEAC: updated token %08x; type %08x; rid %08x\n", token, TypeFromToken(token), RidFromToken(token));
 
         switch (TypeFromToken(token))
         {
             case mdtMethodDef:
 
                 // MethodDef token - update/add a method
-                LOG((LF_ENC, LL_INFO10000, "EACM::AEAC: Found method 0x%x\n", token));
+                LOG((LF_ENC, LL_INFO10000, "EACM::AEAC: Found method %08x\n", token));
 
                 ULONG dwMethodRVA;
                 DWORD dwMethodFlags;
@@ -226,7 +226,7 @@ HRESULT EditAndContinueModule::ApplyEditAndContinue(
 
                 if (dwMethodRVA >= cbDeltaIL)
                 {
-                    LOG((LF_ENC, LL_INFO10000, "EACM::AEAC:   failure RVA of %d with cbDeltaIl %d\n", dwMethodRVA, cbDeltaIL));
+                    LOG((LF_ENC, LL_INFO10000, "EACM::AEAC: Failure RVA of %d with cbDeltaIl %d\n", dwMethodRVA, cbDeltaIL));
                     IfFailGo(E_INVALIDARG);
                 }
 
@@ -251,7 +251,7 @@ HRESULT EditAndContinueModule::ApplyEditAndContinue(
             case mdtFieldDef:
 
                 // FieldDef token - add a new field
-                LOG((LF_ENC, LL_INFO10000, "EACM::AEAC: Found field 0x%x\n", token));
+                LOG((LF_ENC, LL_INFO10000, "EACM::AEAC: Found field %08x\n", token));
 
                 if (LookupFieldDef(token))
                 {
@@ -367,7 +367,7 @@ HRESULT EditAndContinueModule::AddMethod(mdMethodDef token)
     HRESULT hr = GetMDImport()->GetParentToken(token, &parentTypeDef);
     if (FAILED(hr))
     {
-        LOG((LF_ENC, LL_INFO100, "**Error** EnCModule::AM can't find parent token for method token %p\n", token));
+        LOG((LF_ENC, LL_INFO100, "**Error** EnCModule::AM can't find parent token for method token %08x\n", token));
         return E_FAIL;
     }
 
@@ -377,7 +377,7 @@ HRESULT EditAndContinueModule::AddMethod(mdMethodDef token)
     {
         // Class isn't loaded yet, don't have to modify any existing EE data structures beyond the metadata.
         // Just notify debugger and return.
-        LOG((LF_ENC, LL_INFO100, "EnCModule::AM class %p not loaded, our work is done\n", parentTypeDef));
+        LOG((LF_ENC, LL_INFO100, "EnCModule::AM class %08x not loaded (method %08x), our work is done\n", parentTypeDef, token));
         if (CORDebuggerAttached())
         {
             hr = g_pDebugInterface->UpdateNotYetLoadedFunction(token, this, m_applyChangesCount);
@@ -386,14 +386,14 @@ HRESULT EditAndContinueModule::AddMethod(mdMethodDef token)
     }
 
     // Add the method to the runtime's Class data structures
-    LOG((LF_ENC, LL_INFO100000, "EACM::AM: Adding function %p\n", token));
+    LOG((LF_ENC, LL_INFO100000, "EACM::AM: Adding function %08x to type %08x\n", token, parentTypeDef));
     MethodDesc *pMethod = NULL;
     hr = EEClass::AddMethod(pParentType, token, 0, &pMethod);
 
     if (FAILED(hr))
     {
         _ASSERTE(!"Failed to add function");
-        LOG((LF_ENC, LL_INFO100000, "**Error** EACM::AM: Failed to add function %p  with hr 0x%x\n", token));
+        LOG((LF_ENC, LL_INFO100000, "**Error** EACM::AM: Failed to add function %08x with hr %08x\n", token, hr));
         return hr;
     }
 
@@ -404,7 +404,7 @@ HRESULT EditAndContinueModule::AddMethod(mdMethodDef token)
         if (FAILED(hr))
         {
             _ASSERTE(!"Failed to add function");
-            LOG((LF_ENC, LL_INFO100000, "**Error** EACM::AF: Failed to add method %p to debugger with hr 0x%x\n", token));
+            LOG((LF_ENC, LL_INFO100000, "**Error** EACM::AF: Failed to add method %08x to debugger with hr %08x\n", token, hr));
         }
     }
 
@@ -444,7 +444,7 @@ HRESULT EditAndContinueModule::AddField(mdFieldDef token)
 
     if (FAILED(hr))
     {
-        LOG((LF_ENC, LL_INFO100, "**Error** EnCModule::AF can't find parent token for field token %p\n", token));
+        LOG((LF_ENC, LL_INFO100, "**Error** EnCModule::AF can't find parent token for field token %08x\n", token));
         return E_FAIL;
     }
 
@@ -456,18 +456,18 @@ HRESULT EditAndContinueModule::AddField(mdFieldDef token)
     MethodTable * pParentType = LookupTypeDef(parentTypeDef).AsMethodTable();
     if (pParentType == NULL)
     {
-        LOG((LF_ENC, LL_INFO100, "EnCModule::AF class %p not loaded, our work is done\n", parentTypeDef));
+        LOG((LF_ENC, LL_INFO100, "EnCModule::AF class %08x not loaded (field %08x), our work is done\n", parentTypeDef, token));
         return S_OK;
     }
 
     // Create a new EnCFieldDesc for the field and add it to the class
-    LOG((LF_ENC, LL_INFO100000, "EACM::AM: Adding field %p\n", token));
+    LOG((LF_ENC, LL_INFO100000, "EACM::AM: Adding field %08x to type %08x\n", token, parentTypeDef));
     EnCFieldDesc *pField;
     hr = EEClass::AddField(pParentType, token, &pField);
 
     if (FAILED(hr))
     {
-        LOG((LF_ENC, LL_INFO100000, "**Error** EACM::AF: Failed to add field %p to EE  with hr 0x%x\n", token));
+        LOG((LF_ENC, LL_INFO100000, "**Error** EACM::AF: Failed to add field %08x to EE with hr %08x\n", token, hr));
         return hr;
     }
 
@@ -477,7 +477,7 @@ HRESULT EditAndContinueModule::AddField(mdFieldDef token)
         hr = g_pDebugInterface->AddField(pField, m_applyChangesCount);
         if (FAILED(hr))
         {
-            LOG((LF_ENC, LL_INFO100000, "**Error** EACM::AF: Failed to add field %p to debugger with hr 0x%x\n", token));
+            LOG((LF_ENC, LL_INFO100000, "**Error** EACM::AF: Failed to add field %08x to debugger with hr %08x\n", token, hr));
         }
     }
 
@@ -801,7 +801,7 @@ NOINLINE void EditAndContinueModule::FixContextAndResume(
     // Set the new IP
     // Note that all we're really doing here is setting the IP register.  We unfortunately don't
     // share any code with the implementation of debugger SetIP, despite the similarities.
-    LOG((LF_ENC, LL_INFO100, "EnCModule::ResumeInUpdatedFunction: Resume at EIP=0x%x\n", pNewCodeInfo->GetCodeAddress()));
+    LOG((LF_ENC, LL_INFO100, "EnCModule::ResumeInUpdatedFunction: Resume at EIP=%p\n", pNewCodeInfo->GetCodeAddress()));
 
     Thread *pCurThread = GetThread();
     pCurThread->SetFilterContext(pContext);
@@ -1242,7 +1242,7 @@ PTR_CBYTE EnCSyncBlockInfo::ResolveField(OBJECTREF thisPointer, EnCFieldDesc *pF
 
     PTR_EnCAddedField pEntry = NULL;
 
-    LOG((LF_ENC, LL_INFO1000, "EnCSBI:RF for this %p, FD %p\n", OBJECTREFToObject(thisPointer), pFD->GetMemberDef()));
+    LOG((LF_ENC, LL_INFO1000, "EnCSBI:RF for this %p, FD %08x\n", OBJECTREFToObject(thisPointer), pFD->GetMemberDef()));
 
     // This list is not synchronized--it hasn't proved a problem, but we could conceivably see race conditions
     // arise here.
@@ -1316,7 +1316,7 @@ PTR_CBYTE EnCSyncBlockInfo::ResolveOrAllocateField(OBJECTREF thisPointer, EnCFie
     // if the field doesn't yet have available storage, we'll have to allocate it.
     PTR_EnCAddedField pEntry = NULL;
 
-    LOG((LF_ENC, LL_INFO1000, "EnCSBI:RF for this %p, FD %p\n",  OBJECTREFToObject(thisPointer), pFD->GetMemberDef()));
+    LOG((LF_ENC, LL_INFO1000, "EnCSBI:RF for this %p, FD %08x\n",  OBJECTREFToObject(thisPointer), pFD->GetMemberDef()));
 
     // This list is not synchronized--it hasn't proved a problem, but we could conceivably see race conditions
     // arise here.