Figure 1 Functions of the Profiling API
CLR startup and shutdown
Application domain creation/shutdown
Assembly loads/unloads
Module loads/unloads
Class loads/unloads
COM interop VTable creation/destruction
JIT-compiles, code pitching, and pre-JITed method searches
Thread creation/destruction/suspends
Remoting activity
Exception handling
Managed/unmanaged code transitions
Garbage collection and managed heap objects
Method entry/exit
Figure 2 JIT Compilation Methods
JITCompilationStarted
JITCompilationFinished
JITCachedFunctionSearchStarted
JITCachedFunctionSearchFinished
JITFunctionPitched
JITInlining
Figure 3 Threading Methods
ThreadCreated
ThreadDestroyed
ThreadAssignedToOSThread
RuntimeSuspendStarted
RuntimeSuspendFinished
RuntimeSuspendAborted
RuntimeResumeStarted
RuntimeResumeFinished
RuntimeThreadSuspended
RuntimeThreadResumed
Figure 4 Remoting Methods
RemotingClientInvocationStarted
RemotingClientSendingMessage
RemotingClientReceivingReply
RemotingClientInvocationFinished
RemotingServerReceivingMessage
RemotingServerInvocationStarted
RemotingServerInvocationReturned
RemotingServerSendingReply
Figure 5 Exception Methods
ExceptionThrown
ExceptionSearchFunctionEnter
ExceptionSearchFunctionLeave
ExceptionSearchFilterEnter
ExceptionSearchFilterLeave
ExceptionSearchCatcherFound
ExceptionOSHandlerEnter
ExceptionOSHandlerLeave
ExceptionUnwindFunctionEnter
ExceptionUnwindFunctionLeave
ExceptionUnwindFinallyEnter
ExceptionUnwindFinallyLeave
ExceptionCatcherEnter
ExceptionCatcherLeave
ExceptionCLRCatcherFound
ExceptionCLRCatcherExecute
Figure 6 __declspec
void __declspec( naked ) EnterNaked()
{
__asm
{
push eax
push ecx
push edx
push [esp+16]
call RealEnterFunctionInCPP
pop edx
pop ecx
pop eax
ret 4
}
}
Figure 7 ProfilerCallback.cpp
#define WIN32_LEAN_AND_MEAN // Exclude rarely-used stuff from Windows
// headers
#include <windows.h>
#include <stdio.h>
#include "ProfilerCallback.h"
//====================================================
ULONG CProfilerCallback::AddRef()
{
return S_OK;
}
ULONG CProfilerCallback::Release()
{
return S_OK;
}
HRESULT CProfilerCallback::QueryInterface( REFIID riid, void **ppInterface )
{
return E_NOTIMPL;
}
//====================================================
HRESULT CProfilerCallback::Initialize(IUnknown * pICorProfilerInfoUnk )
{
GetInititializationParameters();
if ( m_bBreakOnInitialize ) // Set DN_PROFILER_BREAK environ var to "1"
__asm int 3
// Get the ICorProfilerInfo interface we need, and stuff it away in
// a member variable.
HRESULT hr =
pICorProfilerInfoUnk->QueryInterface( IID_ICorProfilerInfo,
(LPVOID *)&m_pICorProfilerInfo );
if ( FAILED(hr) )
return E_INVALIDARG;
// Indicate which events we're interested in.
// See GetInititializationParameters
m_pICorProfilerInfo->SetEventMask( m_dwEventMask );
// This is the first thread, so set up the per-thread data
// for it. this code is essentially replicated in the
// ::ThreadCreated method
m_tlsIndex = TlsAlloc();
CPerThreadData * pPerThreadData = new CPerThreadData;
pPerThreadData->m_uNestingLevel = 0;
TlsSetValue( m_tlsIndex, pPerThreadData );
// Open the file that we'll write out output to
m_pOutFile = fopen( m_szOutfileName, "wt" );
ProfilerPrintf( "Initialize\n" );
return S_OK;
}
•••
//=============================================================================
// Helper functions
bool CProfilerCallback::GetMethodNameFromFunctionId(FunctionID functionId,
LPWSTR wszClass, LPWSTR wszMethod)
{
mdToken dwToken;
IMetaDataImport * pIMetaDataImport = 0;
HRESULT hr = m_pICorProfilerInfo->GetTokenAndMetaDataFromFunction(
functionId, IID_IMetaDataImport,
(LPUNKNOWN *)&pIMetaDataImport, &dwToken );
if ( FAILED(hr) ) return false;
wchar_t _wszMethod[512];
DWORD cchMethod = sizeof(_wszMethod)/sizeof(_wszMethod[0]);
mdTypeDef mdClass;
hr = pIMetaDataImport->GetMethodProps( dwToken, &mdClass, _wszMethod,
cchMethod, &cchMethod, 0, 0, 0, 0, 0 );
if ( FAILED(hr) ) return false;
lstrcpyW( wszMethod, _wszMethod );
wchar_t wszTypeDef[512];
DWORD cchTypeDef = sizeof(wszTypeDef)/sizeof(wszTypeDef[0]);
if ( mdClass == 0x02000000 )
mdClass = 0x02000001;
hr = pIMetaDataImport->GetTypeDefProps( mdClass, wszTypeDef,
cchTypeDef, &cchTypeDef, 0, 0 );
if ( FAILED(hr) ) return false;
lstrcpyW( wszClass, wszTypeDef );
pIMetaDataImport->Release();
//
// If we were ambitious, we'd save every FunctionID away in a map to
// avoid needing to hit the metatdata APIs every time.
//
return true;
}
bool CProfilerCallback::GetClassNameFromClassId(ClassID classId,
LPWSTR wszClass )
{
ModuleID moduleId;
mdTypeDef typeDef;
wszClass[0] = 0;
HRESULT hr = m_pICorProfilerInfo->GetClassIDInfo( classId, &moduleId,
&typeDef );
if ( FAILED(hr) )
return false;
if ( typeDef == 0 ) // ::GetClassIDInfo can fail, yet not set HRESULT
{
// __asm int 3
return false;
}
IMetaDataImport * pIMetaDataImport = 0;
hr = m_pICorProfilerInfo->GetModuleMetaData( moduleId, ofRead,
IID_IMetaDataImport,
(LPUNKNOWN *)&pIMetaDataImport );
if ( FAILED(hr) )
return false;
if ( !pIMetaDataImport )
return false;
wchar_t wszTypeDef[512];
DWORD cchTypeDef = sizeof(wszTypeDef)/sizeof(wszTypeDef[0]);
hr = pIMetaDataImport->GetTypeDefProps( typeDef, wszTypeDef,
cchTypeDef, &cchTypeDef, 0, 0 );
if ( FAILED(hr) )
return false;
lstrcpyW( wszClass, wszTypeDef );
//
// If we were ambitious, we'd save the ClassID away in a map to avoid
// needing to hit the metatdata APIs every time.
//
pIMetaDataImport->Release();
return true;
}
int CProfilerCallback::ProfilerPrintf(char *pszFormat, ...)
{
char szBuffer[1024];
int retValue;
va_list argptr;
va_start( argptr, pszFormat );
retValue = wvsprintf( szBuffer, pszFormat, argptr );
va_end( argptr );
CPerThreadData * pPerThreadData =
(CPerThreadData*)TlsGetValue(m_tlsIndex);
unsigned uNestingLevel = pPerThreadData->m_uNestingLevel;
// Indent the appropriate amount for the current nesting level
for ( unsigned i = 0; i < uNestingLevel; i++ )
fprintf( m_pOutFile, " " );
fputs( szBuffer, m_pOutFile );
return retValue;
}
void CProfilerCallback::ChangeNestingLevel(int nestingChange)
{
CPerThreadData * pPerThreadData =
(CPerThreadData*)TlsGetValue(m_tlsIndex);
pPerThreadData->m_uNestingLevel += nestingChange;
}
void CProfilerCallback::GetInititializationParameters()
{
// Get name of the EXE we're running in the context of. We're
// going to dump our output file in the same directory as the EXE
GetModuleFileName( 0, m_szOutfileName, sizeof(m_szOutfileName) );
// Overwrite the EXE name with the name of our output file
char * pszLastSlash = strrchr( m_szOutfileName, '\\' );
strcpy( pszLastSlash + 1, "DNProfiler.out" );
// assign reasonable default values to the event mask
m_dwEventMask = COR_PRF_MONITOR_CLASS_LOADS;
m_dwEventMask += COR_PRF_MONITOR_MODULE_LOADS;
m_dwEventMask += COR_PRF_MONITOR_ASSEMBLY_LOADS;
char szProfilerOptions[256];
if ( GetEnvironmentVariable( "DN_PROFILER_MASK", szProfilerOptions,
sizeof(szProfilerOptions) ) )
{
m_dwEventMask = strtoul( szProfilerOptions, 0, 16 );
}
m_bBreakOnInitialize = false;
if ( GetEnvironmentVariable( "DN_PROFILER_BREAK", szProfilerOptions,
sizeof(szProfilerOptions) ) )
{
if ( strtoul( szProfilerOptions, 0, 16 ) > 0 )
m_bBreakOnInitialize = true;
}
}
Figure 8 Sample Output
Initialize
ThreadCreated
ThreadAssignedToOSThread
ThreadCreated
ThreadAssignedToOSThread
AssemblyLoadStarted
ModuleLoadStarted
ModuleLoadFinished:c:\winnt\microsoft.net\framework\v1.0.2914\mscorlib.dll
ModuleAttachedToAssembly: mscorlib
AssemblyLoadFinished: mscorlib Status: 00000000
ClassLoadStarted: System.Object
ClassLoadFinished
ClassLoadStarted: System.ValueType
ClassLoadFinished
ClassLoadStarted: System.ICloneable
ClassLoadFinished
... // lines omitted
ObjectAllocated: System.OutOfMemoryException
ObjectAllocated: System.StackOverflowException
Figure 9 profiling_on.bat
set Cor_Enable_Profiling=0x1
set COR_PROFILER={9AB84088-18E7-42F0-8F8D-E022AE3C4517}
@REM COR_PRF_MONITOR_FUNCTION_UNLOADS = 0x1,
@REM COR_PRF_MONITOR_CLASS_LOADS = 0x2,
@REM COR_PRF_MONITOR_MODULE_LOADS = 0x4,
@REM COR_PRF_MONITOR_ASSEMBLY_LOADS = 0x8,
@REM COR_PRF_MONITOR_APPDOMAIN_LOADS = 0x10,
@REM COR_PRF_MONITOR_JIT_COMPILATION = 0x20,
@REM COR_PRF_MONITOR_EXCEPTIONS = 0x40,
@REM COR_PRF_MONITOR_GC = 0x80,
@REM COR_PRF_MONITOR_OBJECT_ALLOCATED = 0x100,
@REM COR_PRF_MONITOR_THREADS = 0x200,
@REM COR_PRF_MONITOR_REMOTING = 0x400,
@REM COR_PRF_MONITOR_CODE_TRANSITIONS = 0x800,
@REM COR_PRF_MONITOR_ENTERLEAVE = 0x1000,
@REM COR_PRF_MONITOR_CCW = 0x2000,
@REM COR_PRF_MONITOR_REMOTING_COOKIE = 0x4000 |
@REM COR_PRF_MONITOR_REMOTING,
@REM COR_PRF_MONITOR_REMOTING_ASYNC = 0x8000 |
@REM COR_PRF_MONITOR_REMOTING,
@REM COR_PRF_MONITOR_SUSPENDS = 0x10000,
@REM COR_PRF_MONITOR_CACHE_SEARCHES = 0x20000,
@REM COR_PRF_MONITOR_CLR_EXCEPTIONS = 0x1000000,
@REM COR_PRF_MONITOR_ALL = 0x107ffff,
@REM COR_PRF_ENABLE_REJIT = 0x40000,
@REM COR_PRF_ENABLE_INPROC_DEBUGGING = 0x80000,
@REM COR_PRF_ENABLE_JIT_MAPS = 0x100000,
@REM COR_PRF_DISABLE_INLINING = 0x200000,
@REM COR_PRF_DISABLE_OPTIMIZATIONS = 0x400000,
@REM COR_PRF_ENABLE_OBJECT_ALLOCATED = 0x800000,
@REM COR_PRF_ALL = 0x1ffffff,
set DN_PROFILER_MASK=0x1A7ffff
Figure 10 Nesting
ManagedToUnmanagedTransition:
System.Windows.Forms.UnsafeNativeMethods::DispatchMessageW
UnmanagedToManagedTransition: WndProc::Invoke
ManagedToUnmanagedTransition:
System.Windows.Forms.UnsafeNativeMethods::CallWindowProc
UnmanagedToManagedTransition: WndProc::Invoke
ManagedToUnmanagedTransition:
System.Windows.Forms.UnsafeNativeMethods::IntDestroyWindow
UnmanagedToManagedTransition: WndProc::Invoke
ManagedToUnmanagedTransition:
System.Windows.Forms.UnsafeNativeMethods::SendMessage
UnmanagedToManagedTransition: WndProc::Invoke
ManagedToUnmanagedTransition:
System.Windows.Forms.UnsafeNativeMethods::CallWindowProc
|