From 828f7ee67b15b6a406aa31940b6e93bb3a6d3e19 Mon Sep 17 00:00:00 2001 From: lateralusX Date: Thu, 13 Mar 2025 19:57:53 +0100 Subject: [PATCH 1/5] Adjust sources under utilcode and vm to use minipal_log API. --- src/coreclr/utilcode/debug.cpp | 13 ++---- src/coreclr/utilcode/executableallocator.cpp | 32 +++++++------- src/coreclr/utilcode/loaderheap.cpp | 41 +++++++++-------- src/coreclr/utilcode/util_nodependencies.cpp | 2 +- src/coreclr/vm/assembly.cpp | 3 +- src/coreclr/vm/binder.cpp | 22 +++++----- src/coreclr/vm/ceemain.cpp | 2 +- src/coreclr/vm/class.cpp | 2 +- src/coreclr/vm/classcompat.cpp | 16 ++++--- src/coreclr/vm/codeman.h | 3 +- src/coreclr/vm/codepitchingmanager.cpp | 6 +-- src/coreclr/vm/debughelp.cpp | 2 +- src/coreclr/vm/disassembler.cpp | 2 +- src/coreclr/vm/ecall.cpp | 4 +- src/coreclr/vm/eetwain.cpp | 8 ++-- src/coreclr/vm/frames.cpp | 30 +++++++------ src/coreclr/vm/gchelpers.cpp | 46 ++++++++++---------- src/coreclr/vm/gdbjit.cpp | 2 +- src/coreclr/vm/hash.cpp | 12 ++--- src/coreclr/vm/jithelpers.cpp | 2 +- src/coreclr/vm/jitinterface.cpp | 14 +++--- src/coreclr/vm/loaderallocator.cpp | 4 +- src/coreclr/vm/threads.cpp | 6 +-- 23 files changed, 141 insertions(+), 133 deletions(-) diff --git a/src/coreclr/utilcode/debug.cpp b/src/coreclr/utilcode/debug.cpp index 9e56bebac348ba..47eab46628bc91 100644 --- a/src/coreclr/utilcode/debug.cpp +++ b/src/coreclr/utilcode/debug.cpp @@ -202,7 +202,7 @@ HRESULT _OutOfMemory(LPCSTR szFile, int iLine) STATIC_CONTRACT_GC_NOTRIGGER; STATIC_CONTRACT_DEBUG_ONLY; - printf("WARNING: Out of memory condition being issued from: %s, line %d\n", szFile, iLine); + minipal_log_print_info("WARNING: Out of memory condition being issued from: %s, line %d\n", szFile, iLine); return (E_OUTOFMEMORY); } @@ -257,7 +257,7 @@ bool _DbgBreakCheck( if (formattedMessages) { OutputDebugStringUtf8(formatBuffer); - fprintf(stderr, "%s", formatBuffer); + minipal_log_print_error(formatBuffer); } else { @@ -268,12 +268,7 @@ bool _DbgBreakCheck( OutputDebugStringUtf8("\n"); OutputDebugStringUtf8(szExpr); OutputDebugStringUtf8("\n"); - printf("%s", szLowMemoryAssertMessage); - printf("\n"); - printf("%s", szFile); - printf("\n"); - printf("%s", szExpr); - printf("\n"); + minipal_log_print_info("%s\n%s\n%s\n", szLowMemoryAssertMessage, szFile, szExpr); } LogAssert(szFile, iLine, szExpr); @@ -494,7 +489,7 @@ void DECLSPEC_NORETURN __FreeBuildAssertFail(const char *szFile, int iLine, cons OutputDebugStringUtf8(buffer.GetUTF8()); // Write out the error to the console - printf("%s", buffer.GetUTF8()); + minipal_log_print_info(buffer.GetUTF8()); // Log to the stress log. Note that we can't include the szExpr b/c that // may not be a string literal (particularly for formatt-able asserts). diff --git a/src/coreclr/utilcode/executableallocator.cpp b/src/coreclr/utilcode/executableallocator.cpp index eb20b6ab4668bb..29b83ff498b099 100644 --- a/src/coreclr/utilcode/executableallocator.cpp +++ b/src/coreclr/utilcode/executableallocator.cpp @@ -94,27 +94,27 @@ void ExecutableAllocator::DumpHolderUsage() LARGE_INTEGER freq; QueryPerformanceFrequency(&freq); - fprintf(stderr, "Map time with lock sum: %lldms\n", g_mapTimeWithLockSum / (freq.QuadPart / 1000)); - fprintf(stderr, "Map time sum: %lldms\n", g_mapTimeSum / (freq.QuadPart / 1000)); - fprintf(stderr, "Map find RX time sum: %lldms\n", g_mapFindRXTimeSum / (freq.QuadPart / 1000)); - fprintf(stderr, "Map create time sum: %lldms\n", g_mapCreateTimeSum / (freq.QuadPart / 1000)); - fprintf(stderr, "Unmap time with lock sum: %lldms\n", g_unmapTimeWithLockSum / (freq.QuadPart / 1000)); - fprintf(stderr, "Unmap time sum: %lldms\n", g_unmapTimeSum / (freq.QuadPart / 1000)); + minipal_log_print_error("Map time with lock sum: %lldms\n", g_mapTimeWithLockSum / (freq.QuadPart / 1000)); + minipal_log_print_error("Map time sum: %lldms\n", g_mapTimeSum / (freq.QuadPart / 1000)); + minipal_log_print_error("Map find RX time sum: %lldms\n", g_mapFindRXTimeSum / (freq.QuadPart / 1000)); + minipal_log_print_error("Map create time sum: %lldms\n", g_mapCreateTimeSum / (freq.QuadPart / 1000)); + minipal_log_print_error("Unmap time with lock sum: %lldms\n", g_unmapTimeWithLockSum / (freq.QuadPart / 1000)); + minipal_log_print_error("Unmap time sum: %lldms\n", g_unmapTimeSum / (freq.QuadPart / 1000)); - fprintf(stderr, "Reserve count: %lld\n", g_reserveCount); - fprintf(stderr, "Release count: %lld\n", g_releaseCount); + minipal_log_print_error("Reserve count: %lld\n", g_reserveCount); + minipal_log_print_error("Release count: %lld\n", g_releaseCount); - fprintf(stderr, "g_MapRW_Calls: %lld\n", g_MapRW_Calls); - fprintf(stderr, "g_MapRW_CallsWithCacheMiss: %lld\n", g_MapRW_CallsWithCacheMiss); - fprintf(stderr, "g_MapRW_LinkedListWalkDepth: %lld\n", g_MapRW_LinkedListWalkDepth); - fprintf(stderr, "g_MapRW_LinkedListAverageDepth: %f\n", (double)g_MapRW_LinkedListWalkDepth/(double)g_MapRW_CallsWithCacheMiss); - fprintf(stderr, "g_LinkedListTotalDepth: %lld\n", g_LinkedListTotalDepth); + minipal_log_print_error("g_MapRW_Calls: %lld\n", g_MapRW_Calls); + minipal_log_print_error("g_MapRW_CallsWithCacheMiss: %lld\n", g_MapRW_CallsWithCacheMiss); + minipal_log_print_error("g_MapRW_LinkedListWalkDepth: %lld\n", g_MapRW_LinkedListWalkDepth); + minipal_log_print_error("g_MapRW_LinkedListAverageDepth: %f\n", (double)g_MapRW_LinkedListWalkDepth/(double)g_MapRW_CallsWithCacheMiss); + minipal_log_print_error("g_LinkedListTotalDepth: %lld\n", g_LinkedListTotalDepth); - fprintf(stderr, "ExecutableWriterHolder usage:\n"); + minipal_log_print_error("ExecutableWriterHolder usage:\n"); for (int i = 0; i < s_logMaxIndex; i++) { - fprintf(stderr, "Count: %d at %s:%d in %s\n", s_usageLog[i].count, s_usageLog[i].source, s_usageLog[i].line, s_usageLog[i].function); + minipal_log_print_error("Count: %d at %s:%d in %s\n", s_usageLog[i].count, s_usageLog[i].source, s_usageLog[i].line, s_usageLog[i].function); } } @@ -251,7 +251,7 @@ HRESULT ExecutableAllocator::StaticInitialize(FatalErrorHandler fatalErrorHandle { if ((customCacheSize > ARRAY_SIZE(m_cachedMapping)) || (customCacheSize <= 0)) { - printf("Invalid value in 'EXECUTABLE_ALLOCATOR_CACHE_SIZE' environment variable'\n"); + minipal_log_print_info("Invalid value in 'EXECUTABLE_ALLOCATOR_CACHE_SIZE' environment variable'\n"); return E_FAIL; } diff --git a/src/coreclr/utilcode/loaderheap.cpp b/src/coreclr/utilcode/loaderheap.cpp index f6ff925023dbc2..dd7564fec642db 100644 --- a/src/coreclr/utilcode/loaderheap.cpp +++ b/src/coreclr/utilcode/loaderheap.cpp @@ -533,33 +533,36 @@ class LoaderHeapSniffer STATIC_CONTRACT_NOTHROW; STATIC_CONTRACT_FORBID_FAULT; - printf("\n------------- LoaderHeapEvents (in reverse time order!) --------------------"); + minipal_log_print_info("\n------------- LoaderHeapEvents (in reverse time order!) --------------------"); + StackSString buf; LoaderHeapEvent *pEvent = pHeap->m_pEventList; while (pEvent) { - printf("\n"); + minipal_log_print_info("\n"); + switch (pEvent->m_allocationType) { - case kAllocMem: printf("AllocMem "); break; - case kFreedMem: printf("BackoutMem "); break; + case kAllocMem: buf.AppendUTF8("AllocMem "); break; + case kFreedMem: buf.AppendUTF8("BackoutMem "); break; } - printf(" ptr = 0x%-8p", pEvent->m_pMem); - printf(" rqsize = 0x%-8x", (DWORD)pEvent->m_dwRequestedSize); - printf(" actsize = 0x%-8x", (DWORD)pEvent->m_dwSize); - printf(" (at %s@%d)", pEvent->m_szFile, pEvent->m_lineNum); + buf.AppendPrintf(" ptr = 0x%-8p", pEvent->m_pMem); + buf.AppendPrintf(" rqsize = 0x%-8x", (DWORD)pEvent->m_dwRequestedSize); + buf.AppendPrintf(" actsize = 0x%-8x", (DWORD)pEvent->m_dwSize); + buf.AppendPrintf(" (at %s@%d)", pEvent->m_szFile, pEvent->m_lineNum); if (pEvent->m_allocationType == kFreedMem) { - printf(" (original allocation at %s@%d)", pEvent->m_szAllocFile, pEvent->m_allocLineNum); + buf.AppendPrintf(" (original allocation at %s@%d)", pEvent->m_szAllocFile, pEvent->m_allocLineNum); } + minipal_log_print_info(buf.GetUTF8()); + buf.Clear(); + pEvent = pEvent->m_pNext; } - printf("\n------------- End of LoaderHeapEvents --------------------------------------"); - printf("\n"); - + minipal_log_print_info("\n------------- End of LoaderHeapEvents --------------------------------------\n"); } @@ -1925,10 +1928,11 @@ void UnlockedLoaderHeap::DumpFreeList() LIMITED_METHOD_CONTRACT; if (m_pFirstFreeBlock == NULL) { - printf("FREEDUMP: FreeList is empty\n"); + minipal_log_print_info("FREEDUMP: FreeList is empty\n"); } else { + InlineSString<128> buf; LoaderHeapFreeBlock *pBlock = m_pFirstFreeBlock; while (pBlock != NULL) { @@ -1950,10 +1954,13 @@ void UnlockedLoaderHeap::DumpFreeList() } } - printf("Addr = %pxh, Size = %xh", pBlock, ((ULONG)dwsize)); - if (ccbad) printf(" *** ERROR: NOT CC'd ***"); - if (sizeunaligned) printf(" *** ERROR: size not a multiple of ALLOC_ALIGN_CONSTANT ***"); - printf("\n"); + buf.Printf("Addr = %pxh, Size = %xh", pBlock, ((ULONG)dwsize)); + if (ccbad) buf.AppendUTF8(" *** ERROR: NOT CC'd ***"); + if (sizeunaligned) buf.AppendUTF8(" *** ERROR: size not a multiple of ALLOC_ALIGN_CONSTANT ***"); + buf.AppendUTF8("\n"); + + minipal_log_print_info(buf.GetUTF8()); + buf.Clear(); pBlock = pBlock->m_pNext; } diff --git a/src/coreclr/utilcode/util_nodependencies.cpp b/src/coreclr/utilcode/util_nodependencies.cpp index 59f8bcd8edb825..dbb40efb3555c7 100644 --- a/src/coreclr/utilcode/util_nodependencies.cpp +++ b/src/coreclr/utilcode/util_nodependencies.cpp @@ -45,7 +45,7 @@ void InitRunningOnVersionStatus () else { // The current platform isn't supported. Display a message to this effect and exit. - fprintf(stderr, "Platform not supported: Windows 7 is the minimum supported version\n"); + minipal_log_print_error("Platform not supported: Windows 7 is the minimum supported version\n"); TerminateProcess(GetCurrentProcess(), NON_SUPPORTED_PLATFORM_TERMINATE_ERROR_CODE); } #endif // HOST_WINDOWS diff --git a/src/coreclr/vm/assembly.cpp b/src/coreclr/vm/assembly.cpp index 0b4c0f2598aa36..9f16a5d4ee2d92 100644 --- a/src/coreclr/vm/assembly.cpp +++ b/src/coreclr/vm/assembly.cpp @@ -1228,8 +1228,7 @@ static void RunMainInternal(Param* pParam) // // When we get mainCRTStartup from the C++ then this should be able to go away. - fflush(stdout); - fflush(stderr); + minipal_log_flush_all(); } /* static */ diff --git a/src/coreclr/vm/binder.cpp b/src/coreclr/vm/binder.cpp index 7627e5a96c81a8..cde148a18b5dd0 100644 --- a/src/coreclr/vm/binder.cpp +++ b/src/coreclr/vm/binder.cpp @@ -898,7 +898,7 @@ static void FCallCheckSignature(MethodDesc* pMD, PCODE pImpl) // when managed type is well known if (!(strlen(expectedType) == len && SString::_strnicmp(expectedType, pUnmanagedArg, (COUNT_T)len) == 0)) { - printf("CheckExtended: The managed and unmanaged fcall signatures do not match, Method: %s:%s. Argument: %d Expecting: %s Actual: %s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName, argIndex, expectedType, pUnManagedType); + minipal_log_print_info("CheckExtended: The managed and unmanaged fcall signatures do not match, Method: %s:%s. Argument: %d Expecting: %s Actual: %s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName, argIndex, expectedType, pUnManagedType); } } else @@ -928,7 +928,7 @@ static void FCallCheckSignature(MethodDesc* pMD, PCODE pImpl) } if (bSigError) { - printf("CheckExtended: The managed and unmanaged fcall signatures do not match, Method: %s:%s. Argument: %d Expecting: (CorElementType)%d actual: %s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName, argIndex, argType, pUnManagedType); + minipal_log_print_info("CheckExtended: The managed and unmanaged fcall signatures do not match, Method: %s:%s. Argument: %d Expecting: (CorElementType)%d actual: %s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName, argIndex, argType, pUnManagedType); } } pUnmanagedArg = (pUnmanagedArgEnd != NULL) ? (pUnmanagedArgEnd+1) : NULL; @@ -943,14 +943,14 @@ static void FCallCheckSignature(MethodDesc* pMD, PCODE pImpl) { if (!((pUnmanagedArg != NULL) && strcmp(pUnmanagedArg, "...") == 0)) { - printf("CheckExtended: Expecting varargs in unmanaged fcall signature, Method: %s:%s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName); + minipal_log_print_info("CheckExtended: Expecting varargs in unmanaged fcall signature, Method: %s:%s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName); } } else { if (!(pUnmanagedArg == NULL)) { - printf("CheckExtended: Unexpected end of unmanaged fcall signature, Method: %s:%s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName); + minipal_log_print_info("CheckExtended: Unexpected end of unmanaged fcall signature, Method: %s:%s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName); } } } @@ -1042,7 +1042,7 @@ void CoreLibBinder::CheckExtended() if (fError) { - printf("CheckExtended: VM expects type to exist: %s.%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID)); + minipal_log_print_info("CheckExtended: VM expects type to exist: %s.%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID)); } } @@ -1065,7 +1065,7 @@ void CoreLibBinder::CheckExtended() if (fError) { - printf("CheckExtended: VM expects method to exist: %s.%s::%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID), CoreLibBinder::GetMethodName(mID)); + minipal_log_print_info("CheckExtended: VM expects method to exist: %s.%s::%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID), CoreLibBinder::GetMethodName(mID)); } } @@ -1088,7 +1088,7 @@ void CoreLibBinder::CheckExtended() if (fError) { - printf("CheckExtended: VM expects field to exist: %s.%s::%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID), CoreLibBinder::GetFieldName(fID)); + minipal_log_print_info("CheckExtended: VM expects field to exist: %s.%s::%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID), CoreLibBinder::GetFieldName(fID)); } } @@ -1141,7 +1141,7 @@ void CoreLibBinder::CheckExtended() { pszClassName = pszNameSpace = "Invalid TypeDef record"; } - printf("CheckExtended: Unable to load class from System.Private.CoreLib: %s.%s\n", pszNameSpace, pszClassName); + minipal_log_print_info("CheckExtended: Unable to load class from System.Private.CoreLib: %s.%s\n", pszNameSpace, pszClassName); } EX_END_CATCH(SwallowAllExceptions) @@ -1181,7 +1181,7 @@ void CoreLibBinder::CheckExtended() { pszName = "Invalid method name"; } - printf("CheckExtended: Unable to find qcall implementation: %s.%s::%s (EntryPoint name: %s)\n", pszNameSpace, pszClassName, pszName, pNMD->GetEntrypointName()); + minipal_log_print_info("CheckExtended: Unable to find qcall implementation: %s.%s::%s (EntryPoint name: %s)\n", pszNameSpace, pszClassName, pszName, pNMD->GetEntrypointName()); } continue; } @@ -1203,7 +1203,7 @@ void CoreLibBinder::CheckExtended() { pszName = "Invalid method name"; } - printf("CheckExtended: Unable to find internalcall implementation: %s.%s::%s\n", pszNameSpace, pszClassName, pszName); + minipal_log_print_info("CheckExtended: Unable to find internalcall implementation: %s.%s::%s\n", pszNameSpace, pszClassName, pszName); } if (id != 0) @@ -1231,7 +1231,7 @@ void CoreLibBinder::CheckExtended() #define ASMCONSTANTS_RUNTIME_ASSERT(cond) _ASSERTE(cond) #include "asmconstants.h" - printf("CheckExtended: completed without exception.\n"); + minipal_log_print_info("CheckExtended: completed without exception.\n"); ErrExit: _ASSERTE(SUCCEEDED(hr)); diff --git a/src/coreclr/vm/ceemain.cpp b/src/coreclr/vm/ceemain.cpp index 4065b7cc281537..5ab20a218d8ce5 100644 --- a/src/coreclr/vm/ceemain.cpp +++ b/src/coreclr/vm/ceemain.cpp @@ -779,7 +779,7 @@ void EEStartupHelper() Disassembler::StaticInitialize(); if (!Disassembler::IsAvailable()) { - fprintf(stderr, "External disassembler is not available.\n"); + minipal_log_print_error("External disassembler is not available.\n"); IfFailGo(E_FAIL); } } diff --git a/src/coreclr/vm/class.cpp b/src/coreclr/vm/class.cpp index 6120ee32ea696e..23aadb9df202a6 100644 --- a/src/coreclr/vm/class.cpp +++ b/src/coreclr/vm/class.cpp @@ -2498,7 +2498,7 @@ void MethodTable::DebugRecursivelyDumpInstanceFields(LPCUTF8 pszClassName, BOOL { FieldDesc *pFD = &GetClass()->GetFieldDescList()[i]; #ifdef DEBUG_LAYOUT - printf("offset %s%3d %s\n", pFD->IsByValue() ? "byvalue " : "", pFD->GetOffset(), pFD->GetName()); + minipal_log_print_info("offset %s%3d %s\n", pFD->IsByValue() ? "byvalue " : "", pFD->GetOffset(), pFD->GetName()); #endif if(debug) { ssBuff.Printf("offset %3d %s\n", pFD->GetOffset(), pFD->GetName()); diff --git a/src/coreclr/vm/classcompat.cpp b/src/coreclr/vm/classcompat.cpp index 0304440fa41201..ab6376a8b4d3e5 100644 --- a/src/coreclr/vm/classcompat.cpp +++ b/src/coreclr/vm/classcompat.cpp @@ -499,15 +499,15 @@ InteropMethodTableData *MethodTableBuilder::BuildInteropVTable(AllocMemTracker * PCCOR_SIGNATURE pSig; ULONG cbSig; - printf("InteropMethodTable\n--------------\n"); - printf("VTable\n------\n"); + minipal_log_print_info("InteropMethodTable\n--------------\nVTable\n------\n"); + StackSString message; for (DWORD i = 0; i < pInteropMT->cVTable; i++) { // Print the method name InteropMethodTableSlotData *pInteropMD = &pInteropMT->pVTable[i]; - printf(pInteropMD->pMD->GetName()); - printf(" "); + message.AppendUTF8(pInteropMD->pMD->GetName()); + message.AppendUTF8(" "); // Print the sig if (FAILED(pInteropMD->pMD->GetMDImport()->GetSigOfMethodDef(pInteropMD->pMD->GetMemberDef(), &cbSig, &pSig))) @@ -515,9 +515,13 @@ InteropMethodTableData *MethodTableBuilder::BuildInteropVTable(AllocMemTracker * pSig = NULL; cbSig = 0; } + PrettyPrintSigInternalLegacy(pSig, cbSig, "", &qb, pInteropMD->pMD->GetMDImport()); - printf((LPCUTF8) qb.Ptr()); - printf("\n"); + message.AppendUTF8((LPCUTF8) qb.Ptr()); + message.AppendUTF8("\n"); + + minipal_log_print_info(message.GetUTF8()); + message.Clear(); } } #endif // _DEBUG diff --git a/src/coreclr/vm/codeman.h b/src/coreclr/vm/codeman.h index 8a7daf320e0402..128db9b53b4f56 100644 --- a/src/coreclr/vm/codeman.h +++ b/src/coreclr/vm/codeman.h @@ -2431,8 +2431,7 @@ class ExecutionManager static void DumpExecutionManagerUsage() { - fprintf(stderr, "JumpStub usage count:\n"); - fprintf(stderr, "Normal: %u, LCG: %u\n", m_normal_JumpStubLookup, m_LCG_JumpStubLookup); + minipal_log_print_error("JumpStub usage count:\nNormal: %u, LCG: %u\n", m_normal_JumpStubLookup, m_LCG_JumpStubLookup); } struct JumpStubCache diff --git a/src/coreclr/vm/codepitchingmanager.cpp b/src/coreclr/vm/codepitchingmanager.cpp index 3f482b131d0807..f3ca5cae92282b 100644 --- a/src/coreclr/vm/codepitchingmanager.cpp +++ b/src/coreclr/vm/codepitchingmanager.cpp @@ -234,7 +234,7 @@ static void LookupOrCreateInPitchingCandidate(MethodDesc* pMD, ULONG sizeOfCode) const char* szClassName = className.GetUTF8(); const char* szMethodSig = methodSig.GetUTF8(); - printf("Candidate %lu %s :: %s %s\n", + minipal_log_print_info("Candidate %lu %s :: %s %s\n", sizeOfCode, szClassName, pMD->GetName(), szMethodSig); } #endif @@ -415,7 +415,7 @@ void MethodDesc::PitchNativeCode() const char* szClassName = className.GetUTF8(); const char* szMethodSig = methodSig.GetUTF8(); - printf("Pitched %lu %lu %s :: %s %s\n", + minipal_log_print_info("Pitched %lu %lu %s :: %s %s\n", s_PitchedMethodCounter, pitchedBytes, szClassName, GetName(), szMethodSig); } @@ -490,7 +490,7 @@ EXTERN_C void SavePitchingCandidate(MethodDesc* pMD, ULONG sizeOfCode) SimpleWriteLockHolder swlh(s_totalNCSizeLock); s_totalNCSize += sizeOfCode; if (CLRConfig::GetConfigValue(CLRConfig::INTERNAL_JitPitchPrintStat) != 0) - printf("jitted %lu (bytes) pitched %lu (bytes)\n", s_totalNCSize, s_jitPitchedBytes); + minipal_log_print_info("jitted %lu (bytes) pitched %lu (bytes)\n", s_totalNCSize, s_jitPitchedBytes); } } #endif diff --git a/src/coreclr/vm/debughelp.cpp b/src/coreclr/vm/debughelp.cpp index 99ac608c1f1c27..6879495ac95581 100644 --- a/src/coreclr/vm/debughelp.cpp +++ b/src/coreclr/vm/debughelp.cpp @@ -295,7 +295,7 @@ static StackWalkAction PrintStackTraceCallback(CrawlFrame* pCF, VOID* pData) if (pCBD->toStdout) { - printf("%s\n", buff); + minipal_log_print_info("%s\n", buff); } #ifdef _DEBUG else if (pCBD->toLOG) diff --git a/src/coreclr/vm/disassembler.cpp b/src/coreclr/vm/disassembler.cpp index 52c8d6b04c844c..4f5c6775e90834 100644 --- a/src/coreclr/vm/disassembler.cpp +++ b/src/coreclr/vm/disassembler.cpp @@ -67,7 +67,7 @@ bool Disassembler::IsAvailable() } #if _DEBUG -#define DISPLAYERROR(FMT, ...) printf(FMT, __VA_ARGS__) +#define DISPLAYERROR(FMT, ...) minipal_log_print_info(FMT, __VA_ARGS__) #else #define DISPLAYERROR(FMT, ...) (void)0 #endif diff --git a/src/coreclr/vm/ecall.cpp b/src/coreclr/vm/ecall.cpp index 4e67d02a543efa..532f85eaaecedf 100644 --- a/src/coreclr/vm/ecall.cpp +++ b/src/coreclr/vm/ecall.cpp @@ -480,7 +480,7 @@ BOOL ECall::CheckUnusedECalls(SetSHash& usedIDs) if (!usedIDs.Contains(id)) { - printf("CheckCoreLibExtended: Unused ecall found: %s.%s::%s\n", pECClass->m_szNameSpace, c_rgECClasses[ImplsIndex].m_szClassName, ptr->m_szMethodName); + minipal_log_print_info("CheckCoreLibExtended: Unused ecall found: %s.%s::%s\n", pECClass->m_szNameSpace, c_rgECClasses[ImplsIndex].m_szClassName, ptr->m_szMethodName); fUnusedFCallsFound = TRUE; continue; } @@ -490,7 +490,7 @@ BOOL ECall::CheckUnusedECalls(SetSHash& usedIDs) if (fUnreferencedType) { - printf("CheckCoreLibExtended: Unused type found: %s.%s\n", c_rgECClasses[ImplsIndex].m_szNameSpace, c_rgECClasses[ImplsIndex].m_szClassName); + minipal_log_print_info("CheckCoreLibExtended: Unused type found: %s.%s\n", c_rgECClasses[ImplsIndex].m_szNameSpace, c_rgECClasses[ImplsIndex].m_szClassName); fUnusedFCallsFound = TRUE; continue; } diff --git a/src/coreclr/vm/eetwain.cpp b/src/coreclr/vm/eetwain.cpp index d9d0cf5838cc62..2101cd9c75508b 100644 --- a/src/coreclr/vm/eetwain.cpp +++ b/src/coreclr/vm/eetwain.cpp @@ -72,11 +72,11 @@ void EECodeManager::FixContext( ContextType ctxType, #ifdef _DEBUG if (trFixContext) { - printf("FixContext [%s][%s] for %s.%s: ", + minipal_log_print_info("FixContext [%s][%s] for %s.%s: ", stateBuf->hdrInfoBody.ebpFrame?"ebp":" ", stateBuf->hdrInfoBody.interruptible?"int":" ", "UnknownClass","UnknownMethod"); - fflush(stdout); + minipal_log_flush_info(); } #endif @@ -2174,11 +2174,11 @@ TADDR EECodeManager::GetAmbientSP(PREGDISPLAY pContext, #if defined(_DEBUG) && !defined(DACCESS_COMPILE) if (trFixContext) { - printf("GetAmbientSP [%s][%s] for %s.%s: ", + minipal_log_print_info("GetAmbientSP [%s][%s] for %s.%s: ", stateBuf->hdrInfoBody.ebpFrame?"ebp":" ", stateBuf->hdrInfoBody.interruptible?"int":" ", "UnknownClass","UnknownMethod"); - fflush(stdout); + minipal_log_flush_info(); } #endif // _DEBUG && !DACCESS_COMPILE diff --git a/src/coreclr/vm/frames.cpp b/src/coreclr/vm/frames.cpp index f2eeaf8a773b52..7563761bd2236c 100644 --- a/src/coreclr/vm/frames.cpp +++ b/src/coreclr/vm/frames.cpp @@ -2157,10 +2157,12 @@ static void DumpGCRefMap(const char *name, BYTE *address) { GCRefMapDecoder decoder(address); - printf("%s GC ref map: ", name); + StackSString buf; + + buf.Printf("%s GC ref map: ", name); #if TARGET_X86 uint32_t stackPop = decoder.ReadStackPop(); - printf("POP(0x%x)", stackPop); + buf.AppendPrintf("POP(0x%x)", stackPop); #endif int previousToken = GCREFMAP_SKIP; @@ -2172,7 +2174,7 @@ static void DumpGCRefMap(const char *name, BYTE *address) { if (previousToken != GCREFMAP_SKIP) { - printf(") "); + buf.AppendUTF8(") "); } switch (token) { @@ -2180,23 +2182,23 @@ static void DumpGCRefMap(const char *name, BYTE *address) break; case GCREFMAP_REF: - printf("R("); + buf.AppendUTF8("R("); break; case GCREFMAP_INTERIOR: - printf("I("); + buf.AppendUTF8("I("); break; case GCREFMAP_METHOD_PARAM: - printf("M("); + buf.AppendUTF8("M("); break; case GCREFMAP_TYPE_PARAM: - printf("T("); + buf.AppendUTF8("T("); break; case GCREFMAP_VASIG_COOKIE: - printf("V("); + buf.AppendUTF8("V("); break; default: @@ -2206,19 +2208,21 @@ static void DumpGCRefMap(const char *name, BYTE *address) } else if (token != GCREFMAP_SKIP) { - printf(" "); + buf.AppendUTF8(" "); } if (token != GCREFMAP_SKIP) { - printf("%02x", OffsetFromGCRefMapPos(pos)); + buf.AppendPrintf("%02x", OffsetFromGCRefMapPos(pos)); } previousToken = token; } if (previousToken != GCREFMAP_SKIP) { - printf(")"); + buf.AppendUTF8(")"); } - printf("\n"); + buf.AppendUTF8("\n"); + + minipal_log_print_info(buf.GetUTF8()); } #endif @@ -2255,7 +2259,7 @@ bool CheckGCRefMapEqual(PTR_BYTE pGCRefMap, MethodDesc* pMD, bool isDispatchCell } if (invalidGCRefMap) { - printf("GC ref map mismatch detected for method: %s::%s\n", pMD->GetMethodTable()->GetDebugClassName(), pMD->GetName()); + minipal_log_print_info("GC ref map mismatch detected for method: %s::%s\n", pMD->GetMethodTable()->GetDebugClassName(), pMD->GetName()); DumpGCRefMap(" Runtime", (BYTE *)pBlob); DumpGCRefMap("Crossgen2", pGCRefMap); _ASSERTE(false); diff --git a/src/coreclr/vm/gchelpers.cpp b/src/coreclr/vm/gchelpers.cpp index f2476c87c51982..42edb3d7235376 100644 --- a/src/coreclr/vm/gchelpers.cpp +++ b/src/coreclr/vm/gchelpers.cpp @@ -433,7 +433,7 @@ void PublishObjectAndNotify(TObj* &orObject, GC_ALLOC_FLAGS flags) // do this after initializing bounds so callback has size information if (TrackAllocations() || (TrackLargeAllocations() && flags & GC_ALLOC_LARGE_OBJECT_HEAP) || - (TrackPinnedAllocations() && flags & GC_ALLOC_PINNED_OBJECT_HEAP)) + (TrackPinnedAllocations() && flags & GC_ALLOC_PINNED_OBJECT_HEAP)) { OBJECTREF objref = ObjectToOBJECTREF((Object*)orObject); GCPROTECT_BEGIN(objref); @@ -1261,34 +1261,34 @@ static unsigned UncheckedBarrierInterval = BarrierCountPrintInterval; void IncCheckedBarrierCount() { - ++CheckedBarrierCount; - if (--CheckedBarrierInterval == 0) - { - CheckedBarrierInterval = BarrierCountPrintInterval; - printf("GC write barrier counts: checked = %lld, unchecked = %lld, total = %lld.\n", - CheckedBarrierCount, UncheckedBarrierCount, (CheckedBarrierCount + UncheckedBarrierCount)); - printf(" [Checked: %lld after heap check, %lld after ephem check, %lld after already dirty check.]\n", - CheckedAfterHeapFilter, CheckedAfterRefInEphemFilter, CheckedAfterAlreadyDirtyFilter); - printf(" [Unchecked: %lld after ephem check, %lld after already dirty check.]\n", - UncheckedAfterRefInEphemFilter, UncheckedAfterAlreadyDirtyFilter); - printf(" [Dest in ephem: checked = %lld, unchecked = %lld.]\n", - CheckedDestInEphem, UncheckedDestInEphem); - printf(" [Checked: %lld are stores to fields of ret buff, %lld via byref args,\n", + ++CheckedBarrierCount; + if (--CheckedBarrierInterval == 0) + { + CheckedBarrierInterval = BarrierCountPrintInterval; + minipal_log_print_info("GC write barrier counts: checked = %lld, unchecked = %lld, total = %lld.\n", + CheckedBarrierCount, UncheckedBarrierCount, (CheckedBarrierCount + UncheckedBarrierCount)); + minipal_log_print_info(" [Checked: %lld after heap check, %lld after ephem check, %lld after already dirty check.]\n", + CheckedAfterHeapFilter, CheckedAfterRefInEphemFilter, CheckedAfterAlreadyDirtyFilter); + minipal_log_print_info(" [Unchecked: %lld after ephem check, %lld after already dirty check.]\n", + UncheckedAfterRefInEphemFilter, UncheckedAfterAlreadyDirtyFilter); + minipal_log_print_info(" [Dest in ephem: checked = %lld, unchecked = %lld.]\n", + CheckedDestInEphem, UncheckedDestInEphem); + minipal_log_print_info(" [Checked: %lld are stores to fields of ret buff, %lld via byref args,\n", CheckedBarrierRetBufCount, CheckedBarrierByrefArgCount); - printf(" %lld via other locals, %lld via addr of local.]\n", + minipal_log_print_info(" %lld via other locals, %lld via addr of local.]\n", CheckedBarrierByrefOtherLocalCount, CheckedBarrierAddrOfLocalCount); - } + } } void IncUncheckedBarrierCount() { - ++UncheckedBarrierCount; - if (--UncheckedBarrierInterval == 0) - { - printf("GC write barrier counts: checked = %lld, unchecked = %lld, total = %lld.\n", - CheckedBarrierCount, UncheckedBarrierCount, (CheckedBarrierCount + UncheckedBarrierCount)); - UncheckedBarrierInterval = BarrierCountPrintInterval; - } + ++UncheckedBarrierCount; + if (--UncheckedBarrierInterval == 0) + { + minipal_log_print_info("GC write barrier counts: checked = %lld, unchecked = %lld, total = %lld.\n", + CheckedBarrierCount, UncheckedBarrierCount, (CheckedBarrierCount + UncheckedBarrierCount)); + UncheckedBarrierInterval = BarrierCountPrintInterval; + } } #endif // FEATURE_COUNT_GC_WRITE_BARRIERS diff --git a/src/coreclr/vm/gdbjit.cpp b/src/coreclr/vm/gdbjit.cpp index 2a376726e52854..3fc99fb0f1fea8 100644 --- a/src/coreclr/vm/gdbjit.cpp +++ b/src/coreclr/vm/gdbjit.cpp @@ -238,7 +238,7 @@ TypeInfoBase* GetLocalTypeInfo(MethodDesc *methodDescPtr, if (FAILED(methodDescPtr->GetMDImport()->GetSigFromToken(method.GetLocalVarSigTok(), &cbSigLen, &pComSig))) { - printf("\nInvalid record"); + minipal_log_print_info("\nInvalid record"); return nullptr; } diff --git a/src/coreclr/vm/hash.cpp b/src/coreclr/vm/hash.cpp index c3bb80396e1177..159493932e299b 100644 --- a/src/coreclr/vm/hash.cpp +++ b/src/coreclr/vm/hash.cpp @@ -1167,7 +1167,7 @@ HashMap::EnumMemoryRegions(CLRDataEnumMemoryFlags flags) // This is for testing purposes only! void HashMap::HashMapTest() { - printf("HashMap test\n"); + minipal_log_print_info("HashMap test\n"); const unsigned int MinValue = 2; // Deleted is reserved, and is 1. const unsigned int MinThreshold = 10000; @@ -1179,7 +1179,7 @@ void HashMap::HashMapTest() table->Init(10, (CompareFnPtr) NULL, false, &lock); for(unsigned int i=MinValue; i < MinThreshold; i++) table->InsertValue(i, i); - printf("Added %d values.\n", MinThreshold); + minipal_log_print_info("Added %d values.\n", MinThreshold); //table.DumpStatistics(); LookupPerfTest(table, MinThreshold); @@ -1200,7 +1200,7 @@ void HashMap::HashMapTest() if (rep % 500 == 0) { t1 = GetTickCount(); - printf("Repetition %d, took %d ms\n", rep, (int) (t1-t0)); + minipal_log_print_info("Repetition %d, took %d ms\n", rep, (int) (t1-t0)); t0 = t1; LookupPerfTest(table, MinThreshold); //table.DumpStatistics(); @@ -1217,7 +1217,7 @@ void HashMap::LookupPerfTest(HashMap * table, const unsigned int MinThreshold) for(unsigned int i=2; iLookupValue(i, i); if (v != i) { - printf("LookupValue didn't return the expected value!"); + minipal_log_print_info("LookupValue didn't return the expected value!\n"); _ASSERTE(v == i); } } @@ -1227,10 +1227,10 @@ void HashMap::LookupPerfTest(HashMap * table, const unsigned int MinThreshold) table->LookupValue(i, i); //cout << "Lookup perf test (1000 * " << MinThreshold << ": " << (t1-t0) << " ms." << endl; #ifdef HASHTABLE_PROFILE - printf("Lookup perf test time: %d ms table size: %d max failure probe: %d longest collision chain: %d\n", (int) (t1-t0), (int) table->GetSize(table->Buckets()), (int) table->maxFailureProbe, (int) table->m_cbMaxCollisionLength); + minipal_log_print_info("Lookup perf test time: %d ms table size: %d max failure probe: %d longest collision chain: %d\n", (int) (t1-t0), (int) table->GetSize(table->Buckets()), (int) table->maxFailureProbe, (int) table->m_cbMaxCollisionLength); table->DumpStatistics(); #else // !HASHTABLE_PROFILE - printf("Lookup perf test time: %d ms table size: %d\n", (int) (t1-t0), table->GetSize(table->Buckets())); + minipal_log_print_info("Lookup perf test time: %d ms table size: %d\n", (int) (t1-t0), table->GetSize(table->Buckets())); #endif // !HASHTABLE_PROFILE } #endif // !DACCESS_COMPILE diff --git a/src/coreclr/vm/jithelpers.cpp b/src/coreclr/vm/jithelpers.cpp index 9888f615a8489c..a5da1e8d59b991 100644 --- a/src/coreclr/vm/jithelpers.cpp +++ b/src/coreclr/vm/jithelpers.cpp @@ -1997,7 +1997,7 @@ HCIMPL0(void, JIT_DebugLogLoopCloning) } CONTRACTL_END; #ifdef _DEBUG - printf(">> Logging loop cloning optimization\n"); + minipal_log_print_info(">> Logging loop cloning optimization\n"); #endif } HCIMPLEND diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index 7fa84d674018d4..d633519c827f96 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -13412,7 +13412,7 @@ PCODE UnsafeJitFunction(PrepareCodeConfig* config, fHeartbeat = CLRConfig::GetConfigValue(CLRConfig::INTERNAL_JitHeartbeat); if (fHeartbeat) - printf("."); + minipal_log_print_info("."); #endif // _DEBUG timer.Stop(); @@ -13518,7 +13518,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - printf("Type %s: expected size 0x%08x, actual size 0x%08x\n", + minipal_log_print_info("Type %s: expected size 0x%08x, actual size 0x%08x\n", GetFullyQualifiedNameForClass(pMT), dwExpectedSize, dwActualSize); } else @@ -13541,7 +13541,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - printf("Type %s: expected HFA type %08x, actual %08x\n", + minipal_log_print_info("Type %s: expected HFA type %08x, actual %08x\n", GetFullyQualifiedNameForClass(pMT), dwExpectedHFAType, dwActualHFAType); } else @@ -13559,7 +13559,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - printf("Type %s: type is HFA but READYTORUN_LAYOUT_HFA flag is not set\n", + minipal_log_print_info("Type %s: type is HFA but READYTORUN_LAYOUT_HFA flag is not set\n", GetFullyQualifiedNameForClass(pMT)); } else @@ -13588,7 +13588,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - printf("Type %s: expected alignment 0x%08x, actual 0x%08x\n", + minipal_log_print_info("Type %s: expected alignment 0x%08x, actual 0x%08x\n", GetFullyQualifiedNameForClass(pMT), dwExpectedAlignment, dwActualAlignment); } else @@ -13610,7 +13610,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - printf("Type %s contains pointers but READYTORUN_LAYOUT_GCLayout_Empty is set\n", + minipal_log_print_info("Type %s contains pointers but READYTORUN_LAYOUT_GCLayout_Empty is set\n", GetFullyQualifiedNameForClass(pMT)); } else @@ -13635,7 +13635,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - printf("Type %s: GC refmap content doesn't match\n", + minipal_log_print_info("Type %s: GC refmap content doesn't match\n", GetFullyQualifiedNameForClass(pMT)); } else diff --git a/src/coreclr/vm/loaderallocator.cpp b/src/coreclr/vm/loaderallocator.cpp index e58ad1b4ec3e1e..b53138c2f9087d 100644 --- a/src/coreclr/vm/loaderallocator.cpp +++ b/src/coreclr/vm/loaderallocator.cpp @@ -374,12 +374,12 @@ LoaderAllocator * LoaderAllocator::GCLoaderAllocators_RemoveAssemblies(AppDomain LoaderAllocator * pLoaderAllocator = pAssembly->GetLoaderAllocator(); if (pLoaderAllocator->IsCollectible()) { - printf("LA %p ReferencesTo %d\n", pLoaderAllocator, pLoaderAllocator->m_cReferences); + minipal_log_print_info("LA %p ReferencesTo %d\n", pLoaderAllocator, pLoaderAllocator->m_cReferences); LoaderAllocatorSet::Iterator iter = pLoaderAllocator->m_LoaderAllocatorReferences.Begin(); while (iter != pLoaderAllocator->m_LoaderAllocatorReferences.End()) { LoaderAllocator * pAllocator = *iter; - printf("LARefTo: %p\n", pAllocator); + minipal_log_print_info("LARefTo: %p\n", pAllocator); iter++; } } diff --git a/src/coreclr/vm/threads.cpp b/src/coreclr/vm/threads.cpp index 524da3cee22279..a21064d019b663 100644 --- a/src/coreclr/vm/threads.cpp +++ b/src/coreclr/vm/threads.cpp @@ -5482,11 +5482,11 @@ BOOL ThreadStore::DbgFindThread(Thread *target) { // If count is off, try again, to account for multiple threads. if (iRetry < 4) { - // printf("Retry %d. cntReturn:%d, gReturn:%d\n", iRetry, cntReturn, g_TrapReturningThreads); + // minipal_log_print_info("Retry %d. cntReturn:%d, gReturn:%d\n", iRetry, cntReturn, g_TrapReturningThreads); ++iRetry; goto Retry; } - printf("cnt:%d, Un:%d, Back:%d, Dead:%d, cntReturn:%d, TrapReturn:%d, eeShutdown:%d, threadShutdown:%d\n", + minipal_log_print_info("cnt:%d, Un:%d, Back:%d, Dead:%d, cntReturn:%d, TrapReturn:%d, eeShutdown:%d, threadShutdown:%d\n", cnt,cntUnstart,cntBack,cntDead,cntReturn,g_TrapReturningThreads, g_fEEShutDown, Thread::IsAtProcessExit()); LOG((LF_CORDB, LL_INFO1000, "SUSPEND: cnt:%d, Un:%d, Back:%d, Dead:%d, cntReturn:%d, TrapReturn:%d, eeShutdown:%d, threadShutdown:%d\n", @@ -5496,7 +5496,7 @@ BOOL ThreadStore::DbgFindThread(Thread *target) } if (iRetry > 0 && iRetry < 4) { - printf("%d retries to re-sync counted TrapReturn with global TrapReturn.\n", iRetry); + minipal_log_print_info("%d retries to re-sync counted TrapReturn with global TrapReturn.\n", iRetry); } #endif // g_TrapReturningThreads debug code. From 4758043837157eb76ec03bacb8355d7199dddf66 Mon Sep 17 00:00:00 2001 From: lateralusX Date: Mon, 31 Mar 2025 13:04:38 +0200 Subject: [PATCH 2/5] Review feedback. --- src/coreclr/utilcode/executableallocator.cpp | 32 ++++++++++---------- src/coreclr/vm/assembly.cpp | 2 -- src/coreclr/vm/binder.cpp | 4 +-- src/coreclr/vm/codeman.h | 2 +- src/coreclr/vm/disassembler.cpp | 2 +- src/coreclr/vm/frames.cpp | 2 +- src/coreclr/vm/gdbjit.cpp | 2 +- src/coreclr/vm/jitinterface.cpp | 12 ++++---- 8 files changed, 28 insertions(+), 30 deletions(-) diff --git a/src/coreclr/utilcode/executableallocator.cpp b/src/coreclr/utilcode/executableallocator.cpp index 29b83ff498b099..d145ab03987a08 100644 --- a/src/coreclr/utilcode/executableallocator.cpp +++ b/src/coreclr/utilcode/executableallocator.cpp @@ -94,27 +94,27 @@ void ExecutableAllocator::DumpHolderUsage() LARGE_INTEGER freq; QueryPerformanceFrequency(&freq); - minipal_log_print_error("Map time with lock sum: %lldms\n", g_mapTimeWithLockSum / (freq.QuadPart / 1000)); - minipal_log_print_error("Map time sum: %lldms\n", g_mapTimeSum / (freq.QuadPart / 1000)); - minipal_log_print_error("Map find RX time sum: %lldms\n", g_mapFindRXTimeSum / (freq.QuadPart / 1000)); - minipal_log_print_error("Map create time sum: %lldms\n", g_mapCreateTimeSum / (freq.QuadPart / 1000)); - minipal_log_print_error("Unmap time with lock sum: %lldms\n", g_unmapTimeWithLockSum / (freq.QuadPart / 1000)); - minipal_log_print_error("Unmap time sum: %lldms\n", g_unmapTimeSum / (freq.QuadPart / 1000)); + minipal_log_print_info("Map time with lock sum: %lldms\n", g_mapTimeWithLockSum / (freq.QuadPart / 1000)); + minipal_log_print_info("Map time sum: %lldms\n", g_mapTimeSum / (freq.QuadPart / 1000)); + minipal_log_print_info("Map find RX time sum: %lldms\n", g_mapFindRXTimeSum / (freq.QuadPart / 1000)); + minipal_log_print_info("Map create time sum: %lldms\n", g_mapCreateTimeSum / (freq.QuadPart / 1000)); + minipal_log_print_info("Unmap time with lock sum: %lldms\n", g_unmapTimeWithLockSum / (freq.QuadPart / 1000)); + minipal_log_print_info("Unmap time sum: %lldms\n", g_unmapTimeSum / (freq.QuadPart / 1000)); - minipal_log_print_error("Reserve count: %lld\n", g_reserveCount); - minipal_log_print_error("Release count: %lld\n", g_releaseCount); + minipal_log_print_info("Reserve count: %lld\n", g_reserveCount); + minipal_log_print_info("Release count: %lld\n", g_releaseCount); - minipal_log_print_error("g_MapRW_Calls: %lld\n", g_MapRW_Calls); - minipal_log_print_error("g_MapRW_CallsWithCacheMiss: %lld\n", g_MapRW_CallsWithCacheMiss); - minipal_log_print_error("g_MapRW_LinkedListWalkDepth: %lld\n", g_MapRW_LinkedListWalkDepth); - minipal_log_print_error("g_MapRW_LinkedListAverageDepth: %f\n", (double)g_MapRW_LinkedListWalkDepth/(double)g_MapRW_CallsWithCacheMiss); - minipal_log_print_error("g_LinkedListTotalDepth: %lld\n", g_LinkedListTotalDepth); + minipal_log_print_info("g_MapRW_Calls: %lld\n", g_MapRW_Calls); + minipal_log_print_info("g_MapRW_CallsWithCacheMiss: %lld\n", g_MapRW_CallsWithCacheMiss); + minipal_log_print_info("g_MapRW_LinkedListWalkDepth: %lld\n", g_MapRW_LinkedListWalkDepth); + minipal_log_print_info("g_MapRW_LinkedListAverageDepth: %f\n", (double)g_MapRW_LinkedListWalkDepth/(double)g_MapRW_CallsWithCacheMiss); + minipal_log_print_info("g_LinkedListTotalDepth: %lld\n", g_LinkedListTotalDepth); - minipal_log_print_error("ExecutableWriterHolder usage:\n"); + minipal_log_print_info("ExecutableWriterHolder usage:\n"); for (int i = 0; i < s_logMaxIndex; i++) { - minipal_log_print_error("Count: %d at %s:%d in %s\n", s_usageLog[i].count, s_usageLog[i].source, s_usageLog[i].line, s_usageLog[i].function); + minipal_log_print_info("Count: %d at %s:%d in %s\n", s_usageLog[i].count, s_usageLog[i].source, s_usageLog[i].line, s_usageLog[i].function); } } @@ -251,7 +251,7 @@ HRESULT ExecutableAllocator::StaticInitialize(FatalErrorHandler fatalErrorHandle { if ((customCacheSize > ARRAY_SIZE(m_cachedMapping)) || (customCacheSize <= 0)) { - minipal_log_print_info("Invalid value in 'EXECUTABLE_ALLOCATOR_CACHE_SIZE' environment variable'\n"); + minipal_log_print_error("Invalid value in 'EXECUTABLE_ALLOCATOR_CACHE_SIZE' environment variable'\n"); return E_FAIL; } diff --git a/src/coreclr/vm/assembly.cpp b/src/coreclr/vm/assembly.cpp index 9f16a5d4ee2d92..125e7d2b0c6af3 100644 --- a/src/coreclr/vm/assembly.cpp +++ b/src/coreclr/vm/assembly.cpp @@ -1226,8 +1226,6 @@ static void RunMainInternal(Param* pParam) GCPROTECT_END(); - // - // When we get mainCRTStartup from the C++ then this should be able to go away. minipal_log_flush_all(); } diff --git a/src/coreclr/vm/binder.cpp b/src/coreclr/vm/binder.cpp index cde148a18b5dd0..82c9abf874ea9f 100644 --- a/src/coreclr/vm/binder.cpp +++ b/src/coreclr/vm/binder.cpp @@ -898,7 +898,7 @@ static void FCallCheckSignature(MethodDesc* pMD, PCODE pImpl) // when managed type is well known if (!(strlen(expectedType) == len && SString::_strnicmp(expectedType, pUnmanagedArg, (COUNT_T)len) == 0)) { - minipal_log_print_info("CheckExtended: The managed and unmanaged fcall signatures do not match, Method: %s:%s. Argument: %d Expecting: %s Actual: %s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName, argIndex, expectedType, pUnManagedType); + minipal_log_print_error("CheckExtended: The managed and unmanaged fcall signatures do not match, Method: %s:%s. Argument: %d Expecting: %s Actual: %s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName, argIndex, expectedType, pUnManagedType); } } else @@ -928,7 +928,7 @@ static void FCallCheckSignature(MethodDesc* pMD, PCODE pImpl) } if (bSigError) { - minipal_log_print_info("CheckExtended: The managed and unmanaged fcall signatures do not match, Method: %s:%s. Argument: %d Expecting: (CorElementType)%d actual: %s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName, argIndex, argType, pUnManagedType); + minipal_log_print_error("CheckExtended: The managed and unmanaged fcall signatures do not match, Method: %s:%s. Argument: %d Expecting: (CorElementType)%d actual: %s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName, argIndex, argType, pUnManagedType); } } pUnmanagedArg = (pUnmanagedArgEnd != NULL) ? (pUnmanagedArgEnd+1) : NULL; diff --git a/src/coreclr/vm/codeman.h b/src/coreclr/vm/codeman.h index 128db9b53b4f56..f5943e961c285e 100644 --- a/src/coreclr/vm/codeman.h +++ b/src/coreclr/vm/codeman.h @@ -2431,7 +2431,7 @@ class ExecutionManager static void DumpExecutionManagerUsage() { - minipal_log_print_error("JumpStub usage count:\nNormal: %u, LCG: %u\n", m_normal_JumpStubLookup, m_LCG_JumpStubLookup); + minipal_log_print_info("JumpStub usage count:\nNormal: %u, LCG: %u\n", m_normal_JumpStubLookup, m_LCG_JumpStubLookup); } struct JumpStubCache diff --git a/src/coreclr/vm/disassembler.cpp b/src/coreclr/vm/disassembler.cpp index 4f5c6775e90834..e5f01eb4e8005e 100644 --- a/src/coreclr/vm/disassembler.cpp +++ b/src/coreclr/vm/disassembler.cpp @@ -67,7 +67,7 @@ bool Disassembler::IsAvailable() } #if _DEBUG -#define DISPLAYERROR(FMT, ...) minipal_log_print_info(FMT, __VA_ARGS__) +#define DISPLAYERROR(FMT, ...) minipal_log_print_error(FMT, __VA_ARGS__) #else #define DISPLAYERROR(FMT, ...) (void)0 #endif diff --git a/src/coreclr/vm/frames.cpp b/src/coreclr/vm/frames.cpp index 7563761bd2236c..7e628564185c3a 100644 --- a/src/coreclr/vm/frames.cpp +++ b/src/coreclr/vm/frames.cpp @@ -2259,7 +2259,7 @@ bool CheckGCRefMapEqual(PTR_BYTE pGCRefMap, MethodDesc* pMD, bool isDispatchCell } if (invalidGCRefMap) { - minipal_log_print_info("GC ref map mismatch detected for method: %s::%s\n", pMD->GetMethodTable()->GetDebugClassName(), pMD->GetName()); + minipal_log_print_error("GC ref map mismatch detected for method: %s::%s\n", pMD->GetMethodTable()->GetDebugClassName(), pMD->GetName()); DumpGCRefMap(" Runtime", (BYTE *)pBlob); DumpGCRefMap("Crossgen2", pGCRefMap); _ASSERTE(false); diff --git a/src/coreclr/vm/gdbjit.cpp b/src/coreclr/vm/gdbjit.cpp index 3fc99fb0f1fea8..f6a92c0e4eb1a2 100644 --- a/src/coreclr/vm/gdbjit.cpp +++ b/src/coreclr/vm/gdbjit.cpp @@ -238,7 +238,7 @@ TypeInfoBase* GetLocalTypeInfo(MethodDesc *methodDescPtr, if (FAILED(methodDescPtr->GetMDImport()->GetSigFromToken(method.GetLocalVarSigTok(), &cbSigLen, &pComSig))) { - minipal_log_print_info("\nInvalid record"); + minipal_log_print_error("\nInvalid record"); return nullptr; } diff --git a/src/coreclr/vm/jitinterface.cpp b/src/coreclr/vm/jitinterface.cpp index d633519c827f96..60ba93eaa82f52 100644 --- a/src/coreclr/vm/jitinterface.cpp +++ b/src/coreclr/vm/jitinterface.cpp @@ -13518,7 +13518,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - minipal_log_print_info("Type %s: expected size 0x%08x, actual size 0x%08x\n", + minipal_log_print_error("Type %s: expected size 0x%08x, actual size 0x%08x\n", GetFullyQualifiedNameForClass(pMT), dwExpectedSize, dwActualSize); } else @@ -13541,7 +13541,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - minipal_log_print_info("Type %s: expected HFA type %08x, actual %08x\n", + minipal_log_print_error("Type %s: expected HFA type %08x, actual %08x\n", GetFullyQualifiedNameForClass(pMT), dwExpectedHFAType, dwActualHFAType); } else @@ -13559,7 +13559,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - minipal_log_print_info("Type %s: type is HFA but READYTORUN_LAYOUT_HFA flag is not set\n", + minipal_log_print_error("Type %s: type is HFA but READYTORUN_LAYOUT_HFA flag is not set\n", GetFullyQualifiedNameForClass(pMT)); } else @@ -13588,7 +13588,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - minipal_log_print_info("Type %s: expected alignment 0x%08x, actual 0x%08x\n", + minipal_log_print_error("Type %s: expected alignment 0x%08x, actual 0x%08x\n", GetFullyQualifiedNameForClass(pMT), dwExpectedAlignment, dwActualAlignment); } else @@ -13610,7 +13610,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - minipal_log_print_info("Type %s contains pointers but READYTORUN_LAYOUT_GCLayout_Empty is set\n", + minipal_log_print_error("Type %s contains pointers but READYTORUN_LAYOUT_GCLayout_Empty is set\n", GetFullyQualifiedNameForClass(pMT)); } else @@ -13635,7 +13635,7 @@ BOOL TypeLayoutCheck(MethodTable * pMT, PCCOR_SIGNATURE pBlob, BOOL printDiff) result = FALSE; DefineFullyQualifiedNameForClass(); - minipal_log_print_info("Type %s: GC refmap content doesn't match\n", + minipal_log_print_error("Type %s: GC refmap content doesn't match\n", GetFullyQualifiedNameForClass(pMT)); } else From aa4e6603b1bff1c16bc5faf8550af5c91fb55cff Mon Sep 17 00:00:00 2001 From: lateralusX Date: Tue, 1 Apr 2025 11:31:08 +0200 Subject: [PATCH 3/5] Review feedback, convert some more info -> error logging. --- src/coreclr/utilcode/debug.cpp | 4 ++-- src/coreclr/vm/binder.cpp | 16 ++++++++-------- src/coreclr/vm/ecall.cpp | 4 ++-- 3 files changed, 12 insertions(+), 12 deletions(-) diff --git a/src/coreclr/utilcode/debug.cpp b/src/coreclr/utilcode/debug.cpp index 47eab46628bc91..dca1d85bb204bd 100644 --- a/src/coreclr/utilcode/debug.cpp +++ b/src/coreclr/utilcode/debug.cpp @@ -268,7 +268,7 @@ bool _DbgBreakCheck( OutputDebugStringUtf8("\n"); OutputDebugStringUtf8(szExpr); OutputDebugStringUtf8("\n"); - minipal_log_print_info("%s\n%s\n%s\n", szLowMemoryAssertMessage, szFile, szExpr); + minipal_log_print_error("%s\n%s\n%s\n", szLowMemoryAssertMessage, szFile, szExpr); } LogAssert(szFile, iLine, szExpr); @@ -489,7 +489,7 @@ void DECLSPEC_NORETURN __FreeBuildAssertFail(const char *szFile, int iLine, cons OutputDebugStringUtf8(buffer.GetUTF8()); // Write out the error to the console - minipal_log_print_info(buffer.GetUTF8()); + minipal_log_print_error(buffer.GetUTF8()); // Log to the stress log. Note that we can't include the szExpr b/c that // may not be a string literal (particularly for formatt-able asserts). diff --git a/src/coreclr/vm/binder.cpp b/src/coreclr/vm/binder.cpp index 82c9abf874ea9f..1a0f4dc2c143b3 100644 --- a/src/coreclr/vm/binder.cpp +++ b/src/coreclr/vm/binder.cpp @@ -943,14 +943,14 @@ static void FCallCheckSignature(MethodDesc* pMD, PCODE pImpl) { if (!((pUnmanagedArg != NULL) && strcmp(pUnmanagedArg, "...") == 0)) { - minipal_log_print_info("CheckExtended: Expecting varargs in unmanaged fcall signature, Method: %s:%s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName); + minipal_log_print_error("CheckExtended: Expecting varargs in unmanaged fcall signature, Method: %s:%s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName); } } else { if (!(pUnmanagedArg == NULL)) { - minipal_log_print_info("CheckExtended: Unexpected end of unmanaged fcall signature, Method: %s:%s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName); + minipal_log_print_error("CheckExtended: Unexpected end of unmanaged fcall signature, Method: %s:%s\n", pMD->m_pszDebugClassName, pMD->m_pszDebugMethodName); } } } @@ -1042,7 +1042,7 @@ void CoreLibBinder::CheckExtended() if (fError) { - minipal_log_print_info("CheckExtended: VM expects type to exist: %s.%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID)); + minipal_log_print_error("CheckExtended: VM expects type to exist: %s.%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID)); } } @@ -1065,7 +1065,7 @@ void CoreLibBinder::CheckExtended() if (fError) { - minipal_log_print_info("CheckExtended: VM expects method to exist: %s.%s::%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID), CoreLibBinder::GetMethodName(mID)); + minipal_log_print_error("CheckExtended: VM expects method to exist: %s.%s::%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID), CoreLibBinder::GetMethodName(mID)); } } @@ -1088,7 +1088,7 @@ void CoreLibBinder::CheckExtended() if (fError) { - minipal_log_print_info("CheckExtended: VM expects field to exist: %s.%s::%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID), CoreLibBinder::GetFieldName(fID)); + minipal_log_print_error("CheckExtended: VM expects field to exist: %s.%s::%s\n", CoreLibBinder::GetClassNameSpace(cID), CoreLibBinder::GetClassName(cID), CoreLibBinder::GetFieldName(fID)); } } @@ -1141,7 +1141,7 @@ void CoreLibBinder::CheckExtended() { pszClassName = pszNameSpace = "Invalid TypeDef record"; } - minipal_log_print_info("CheckExtended: Unable to load class from System.Private.CoreLib: %s.%s\n", pszNameSpace, pszClassName); + minipal_log_print_errpr("CheckExtended: Unable to load class from System.Private.CoreLib: %s.%s\n", pszNameSpace, pszClassName); } EX_END_CATCH(SwallowAllExceptions) @@ -1181,7 +1181,7 @@ void CoreLibBinder::CheckExtended() { pszName = "Invalid method name"; } - minipal_log_print_info("CheckExtended: Unable to find qcall implementation: %s.%s::%s (EntryPoint name: %s)\n", pszNameSpace, pszClassName, pszName, pNMD->GetEntrypointName()); + minipal_log_print_error("CheckExtended: Unable to find qcall implementation: %s.%s::%s (EntryPoint name: %s)\n", pszNameSpace, pszClassName, pszName, pNMD->GetEntrypointName()); } continue; } @@ -1203,7 +1203,7 @@ void CoreLibBinder::CheckExtended() { pszName = "Invalid method name"; } - minipal_log_print_info("CheckExtended: Unable to find internalcall implementation: %s.%s::%s\n", pszNameSpace, pszClassName, pszName); + minipal_log_print_error("CheckExtended: Unable to find internalcall implementation: %s.%s::%s\n", pszNameSpace, pszClassName, pszName); } if (id != 0) diff --git a/src/coreclr/vm/ecall.cpp b/src/coreclr/vm/ecall.cpp index 532f85eaaecedf..993a1299c3ee01 100644 --- a/src/coreclr/vm/ecall.cpp +++ b/src/coreclr/vm/ecall.cpp @@ -480,7 +480,7 @@ BOOL ECall::CheckUnusedECalls(SetSHash& usedIDs) if (!usedIDs.Contains(id)) { - minipal_log_print_info("CheckCoreLibExtended: Unused ecall found: %s.%s::%s\n", pECClass->m_szNameSpace, c_rgECClasses[ImplsIndex].m_szClassName, ptr->m_szMethodName); + minipal_log_print_error("CheckCoreLibExtended: Unused ecall found: %s.%s::%s\n", pECClass->m_szNameSpace, c_rgECClasses[ImplsIndex].m_szClassName, ptr->m_szMethodName); fUnusedFCallsFound = TRUE; continue; } @@ -490,7 +490,7 @@ BOOL ECall::CheckUnusedECalls(SetSHash& usedIDs) if (fUnreferencedType) { - minipal_log_print_info("CheckCoreLibExtended: Unused type found: %s.%s\n", c_rgECClasses[ImplsIndex].m_szNameSpace, c_rgECClasses[ImplsIndex].m_szClassName); + minipal_log_print_error("CheckCoreLibExtended: Unused type found: %s.%s\n", c_rgECClasses[ImplsIndex].m_szNameSpace, c_rgECClasses[ImplsIndex].m_szClassName); fUnusedFCallsFound = TRUE; continue; } From c4202794e4fbd0758effe1426a9b642324ce7ab2 Mon Sep 17 00:00:00 2001 From: lateralusX Date: Tue, 1 Apr 2025 11:35:42 +0200 Subject: [PATCH 4/5] Log OOM as a warning instead of info. --- src/coreclr/utilcode/debug.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/coreclr/utilcode/debug.cpp b/src/coreclr/utilcode/debug.cpp index dca1d85bb204bd..eeb026549280be 100644 --- a/src/coreclr/utilcode/debug.cpp +++ b/src/coreclr/utilcode/debug.cpp @@ -202,7 +202,7 @@ HRESULT _OutOfMemory(LPCSTR szFile, int iLine) STATIC_CONTRACT_GC_NOTRIGGER; STATIC_CONTRACT_DEBUG_ONLY; - minipal_log_print_info("WARNING: Out of memory condition being issued from: %s, line %d\n", szFile, iLine); + minipal_log_print(minipal_log_flags_warning, "WARNING: Out of memory condition being issued from: %s, line %d\n", szFile, iLine); return (E_OUTOFMEMORY); } From 6cd01d3dd60b01404bb9c571d5947713e4c25ff5 Mon Sep 17 00:00:00 2001 From: lateralusX Date: Tue, 1 Apr 2025 12:38:13 +0200 Subject: [PATCH 5/5] Fix typo. --- src/coreclr/vm/binder.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/coreclr/vm/binder.cpp b/src/coreclr/vm/binder.cpp index 1a0f4dc2c143b3..c60ced8f4cb26c 100644 --- a/src/coreclr/vm/binder.cpp +++ b/src/coreclr/vm/binder.cpp @@ -1141,7 +1141,7 @@ void CoreLibBinder::CheckExtended() { pszClassName = pszNameSpace = "Invalid TypeDef record"; } - minipal_log_print_errpr("CheckExtended: Unable to load class from System.Private.CoreLib: %s.%s\n", pszNameSpace, pszClassName); + minipal_log_print_error("CheckExtended: Unable to load class from System.Private.CoreLib: %s.%s\n", pszNameSpace, pszClassName); } EX_END_CATCH(SwallowAllExceptions)