© 2004 Microsoft Corporation. All rights reserved.

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