407 lines
13 KiB
C++
407 lines
13 KiB
C++
//========= Copyright Valve Corporation, All rights reserved. ============//
|
|
//
|
|
// ETW (Event Tracing for Windows) profiling helpers.
|
|
// This allows easy insertion of Generic Event markers into ETW/xperf tracing
|
|
// which then aids in analyzing the traces and finding performance problems.
|
|
//
|
|
//===============================================================================
|
|
|
|
#include "pch_tier0.h"
|
|
#include "tier0/etwprof.h"
|
|
|
|
#ifdef ETW_MARKS_ENABLED
|
|
|
|
#include <memory>
|
|
|
|
// After building the DLL if it has never been registered on this machine or
|
|
// if the providers have changed you need to go:
|
|
// xcopy /y %vgame%\bin\tier0.dll %temp%
|
|
// wevtutil um %vgame%\..\src\tier0\ValveETWProvider.man
|
|
// wevtutil im %vgame%\..\src\tier0\ValveETWProvider.man
|
|
|
|
#define WIN32_LEAN_AND_MEAN
|
|
#include <windows.h>
|
|
// These are defined in evntrace.h but you need a Vista+ Windows
|
|
// SDK to have them available, so I define them here.
|
|
#define EVENT_CONTROL_CODE_DISABLE_PROVIDER 0
|
|
#define EVENT_CONTROL_CODE_ENABLE_PROVIDER 1
|
|
#define EVENT_CONTROL_CODE_CAPTURE_STATE 2
|
|
|
|
// EVNTAPI is used in evntprov.h which is included by ValveETWProviderEvents.h
|
|
// We define EVNTAPI without the DECLSPEC_IMPORT specifier so that
|
|
// we can implement these functions locally instead of using the import library,
|
|
// and can therefore still run on Windows XP.
|
|
#define EVNTAPI __stdcall
|
|
// Include the event register/write/unregister macros compiled from the manifest file.
|
|
// Note that this includes evntprov.h which requires a Vista+ Windows SDK
|
|
// which we don't currently have, so evntprov.h is checked in.
|
|
#include "ValveETWProviderEvents.h"
|
|
|
|
// Typedefs for use with GetProcAddress
|
|
typedef ULONG (__stdcall *tEventRegister)( LPCGUID ProviderId, PENABLECALLBACK EnableCallback, PVOID CallbackContext, PREGHANDLE RegHandle);
|
|
typedef ULONG (__stdcall *tEventWrite)( REGHANDLE RegHandle, PCEVENT_DESCRIPTOR EventDescriptor, ULONG UserDataCount, PEVENT_DATA_DESCRIPTOR UserData);
|
|
typedef ULONG (__stdcall *tEventUnregister)( REGHANDLE RegHandle );
|
|
|
|
// Helper class to dynamically load Advapi32.dll, find the ETW functions,
|
|
// register the providers if possible, and get the performance counter frequency.
|
|
class CETWRegister
|
|
{
|
|
public:
|
|
CETWRegister()
|
|
{
|
|
QueryPerformanceFrequency( &m_frequency );
|
|
|
|
// Find Advapi32.dll. This should always succeed.
|
|
HMODULE pAdvapiDLL = LoadLibraryW( L"Advapi32.dll" );
|
|
if ( pAdvapiDLL )
|
|
{
|
|
// Try to find the ETW functions. This will fail on XP.
|
|
m_pEventRegister = ( tEventRegister )GetProcAddress( pAdvapiDLL, "EventRegister" );
|
|
m_pEventWrite = ( tEventWrite )GetProcAddress( pAdvapiDLL, "EventWrite" );
|
|
m_pEventUnregister = ( tEventUnregister )GetProcAddress( pAdvapiDLL, "EventUnregister" );
|
|
|
|
// Register two ETW providers. If registration fails then the event logging calls will fail.
|
|
// On XP these calls will do nothing.
|
|
// On Vista and above, if these providers have been enabled by xperf or logman then
|
|
// the VALVE_FRAMERATE_Context and VALVE_MAIN_Context globals will be modified
|
|
// like this:
|
|
// MatchAnyKeyword: 0xffffffffffffffff
|
|
// IsEnabled: 1
|
|
// Level: 255
|
|
// In other words, fully enabled.
|
|
|
|
EventRegisterValve_FrameRate();
|
|
EventRegisterValve_ServerFrameRate();
|
|
EventRegisterValve_Main();
|
|
EventRegisterValve_Input();
|
|
EventRegisterValve_Network();
|
|
|
|
// Emit the thread ID for the main thread. This also indicates that
|
|
// the main provider is initialized.
|
|
EventWriteThread_ID( GetCurrentThreadId(), "Main thread" );
|
|
// Emit an input system event so we know that it is active.
|
|
EventWriteKey_down( "Valve input provider initialized.", 0, 0 );
|
|
}
|
|
}
|
|
~CETWRegister()
|
|
{
|
|
// Unregister our providers.
|
|
EventUnregisterValve_Network();
|
|
EventUnregisterValve_Input();
|
|
EventUnregisterValve_Main();
|
|
EventUnregisterValve_ServerFrameRate();
|
|
EventUnregisterValve_FrameRate();
|
|
}
|
|
|
|
tEventRegister m_pEventRegister;
|
|
tEventWrite m_pEventWrite;
|
|
tEventUnregister m_pEventUnregister;
|
|
|
|
// QPC frequency
|
|
LARGE_INTEGER m_frequency;
|
|
|
|
} g_ETWRegister;
|
|
|
|
// Redirector function for EventRegister. Called by macros in ValveETWProviderEvents.h
|
|
ULONG EVNTAPI EventRegister( LPCGUID ProviderId, PENABLECALLBACK EnableCallback, PVOID CallbackContext, PREGHANDLE RegHandle )
|
|
{
|
|
if ( g_ETWRegister.m_pEventRegister )
|
|
return g_ETWRegister.m_pEventRegister( ProviderId, EnableCallback, CallbackContext, RegHandle );
|
|
|
|
// RegHandle is an _Out_ parameter and must always be initialized.
|
|
*RegHandle = 0;
|
|
return 0;
|
|
}
|
|
|
|
// Redirector function for EventWrite. Called by macros in ValveETWProviderEvents.h
|
|
ULONG EVNTAPI EventWrite( REGHANDLE RegHandle, PCEVENT_DESCRIPTOR EventDescriptor, ULONG UserDataCount, PEVENT_DATA_DESCRIPTOR UserData )
|
|
{
|
|
if ( g_ETWRegister.m_pEventWrite )
|
|
return g_ETWRegister.m_pEventWrite( RegHandle, EventDescriptor, UserDataCount, UserData );
|
|
return 0;
|
|
}
|
|
|
|
// Redirector function for EventUnregister. Called by macros in ValveETWProviderEvents.h
|
|
ULONG EVNTAPI EventUnregister( REGHANDLE RegHandle )
|
|
{
|
|
if ( g_ETWRegister.m_pEventUnregister )
|
|
return g_ETWRegister.m_pEventUnregister( RegHandle );
|
|
return 0;
|
|
}
|
|
|
|
// Call QueryPerformanceCounter
|
|
static int64 GetQPCTime()
|
|
{
|
|
LARGE_INTEGER time;
|
|
|
|
QueryPerformanceCounter( &time );
|
|
return time.QuadPart;
|
|
}
|
|
|
|
// Convert a QueryPerformanceCounter delta into milliseconds
|
|
static float QPCToMS( int64 nDelta )
|
|
{
|
|
// Convert from a QPC delta to seconds.
|
|
float flSeconds = ( float )( nDelta / double( g_ETWRegister.m_frequency.QuadPart ) );
|
|
|
|
// Convert from seconds to milliseconds
|
|
return flSeconds * 1000;
|
|
}
|
|
|
|
// Public functions for emitting ETW events.
|
|
|
|
int64 ETWMark( const char *pMessage )
|
|
{
|
|
int64 nTime = GetQPCTime();
|
|
EventWriteMark( pMessage );
|
|
return nTime;
|
|
}
|
|
|
|
void ETWMarkPrintf( const char *pMessage, ... )
|
|
{
|
|
// If we are running on Windows XP or if our providers have not been enabled
|
|
// (by xperf or other) then this will be false and we can early out.
|
|
// Be sure to check the appropriate context for the event. This is only
|
|
// worth checking if there is some cost beyond the EventWrite that we can
|
|
// avoid -- the redirectors in this file guarantee that EventWrite is always
|
|
// safe to call.
|
|
if ( !VALVE_MAIN_Context.IsEnabled )
|
|
{
|
|
return;
|
|
}
|
|
|
|
char buffer[1000];
|
|
va_list args;
|
|
va_start( args, pMessage );
|
|
vsprintf_s( buffer, pMessage, args );
|
|
va_end( args );
|
|
|
|
EventWriteMark( buffer );
|
|
}
|
|
|
|
void ETWMark1F( const char *pMessage, float data1 )
|
|
{
|
|
EventWriteMark1F( pMessage, data1 );
|
|
}
|
|
|
|
void ETWMark2F( const char *pMessage, float data1, float data2 )
|
|
{
|
|
EventWriteMark2F( pMessage, data1, data2 );
|
|
}
|
|
|
|
void ETWMark3F( const char *pMessage, float data1, float data2, float data3 )
|
|
{
|
|
EventWriteMark3F( pMessage, data1, data2, data3 );
|
|
}
|
|
|
|
void ETWMark4F( const char *pMessage, float data1, float data2, float data3, float data4 )
|
|
{
|
|
EventWriteMark4F( pMessage, data1, data2, data3, data4 );
|
|
}
|
|
|
|
void ETWMark1I( const char *pMessage, int data1 )
|
|
{
|
|
EventWriteMark1I( pMessage, data1 );
|
|
}
|
|
|
|
void ETWMark2I( const char *pMessage, int data1, int data2 )
|
|
{
|
|
EventWriteMark2I( pMessage, data1, data2 );
|
|
}
|
|
|
|
void ETWMark3I( const char *pMessage, int data1, int data2, int data3 )
|
|
{
|
|
EventWriteMark3I( pMessage, data1, data2, data3 );
|
|
}
|
|
|
|
void ETWMark4I( const char *pMessage, int data1, int data2, int data3, int data4 )
|
|
{
|
|
EventWriteMark4I( pMessage, data1, data2, data3, data4 );
|
|
}
|
|
|
|
void ETWMark1S( const char *pMessage, const char* data1 )
|
|
{
|
|
EventWriteMark1S( pMessage, data1 );
|
|
}
|
|
|
|
void ETWMark2S( const char *pMessage, const char* data1, const char* data2 )
|
|
{
|
|
EventWriteMark2S( pMessage, data1, data2 );
|
|
}
|
|
|
|
// Track the depth of ETW Begin/End pairs. This needs to be per-thread
|
|
// if we start emitting marks on multiple threads. Using __declspec(thread)
|
|
// has some problems on Windows XP, but since these ETW functions only work
|
|
// on Vista+ that doesn't matter.
|
|
static __declspec( thread ) int s_nDepth;
|
|
|
|
int64 ETWBegin( const char *pMessage )
|
|
{
|
|
// If we are running on Windows XP or if our providers have not been enabled
|
|
// (by xperf or other) then this will be false and we can early out.
|
|
// Be sure to check the appropriate context for the event. This is only
|
|
// worth checking if there is some cost beyond the EventWrite that we can
|
|
// avoid -- the redirectors in this file guarantee that EventWrite is always
|
|
// safe to call.
|
|
// In this case we also avoid the potentially unreliable TLS implementation
|
|
// (for dynamically loaded DLLs) on Windows XP.
|
|
if ( !VALVE_MAIN_Context.IsEnabled )
|
|
{
|
|
return 0;
|
|
}
|
|
|
|
int64 nTime = GetQPCTime();
|
|
EventWriteStart( pMessage, s_nDepth++ );
|
|
return nTime;
|
|
}
|
|
|
|
int64 ETWEnd( const char *pMessage, int64 nStartTime )
|
|
{
|
|
// If we are running on Windows XP or if our providers have not been enabled
|
|
// (by xperf or other) then this will be false and we can early out.
|
|
// Be sure to check the appropriate context for the event. This is only
|
|
// worth checking if there is some cost beyond the EventWrite that we can
|
|
// avoid -- the redirectors in this file guarantee that EventWrite is always
|
|
// safe to call.
|
|
// In this case we also avoid the potentially unreliable TLS implementation
|
|
// (for dynamically loaded DLLs) on Windows XP.
|
|
if ( !VALVE_MAIN_Context.IsEnabled )
|
|
{
|
|
return 0;
|
|
}
|
|
|
|
int64 nTime = GetQPCTime();
|
|
EventWriteStop( pMessage, --s_nDepth, QPCToMS( nTime - nStartTime ) );
|
|
return nTime;
|
|
}
|
|
|
|
// Record server and client frame counts separately, in case they are
|
|
// in the same process.
|
|
static int s_nRenderFrameCount[2];
|
|
|
|
int ETWGetRenderFrameNumber()
|
|
{
|
|
return s_nRenderFrameCount[0];
|
|
}
|
|
|
|
// Insert a render frame marker using the Valve-FrameRate provider. Automatically
|
|
// count the frame number and frame time.
|
|
void ETWRenderFrameMark( bool bIsServerProcess )
|
|
{
|
|
Assert( bIsServerProcess == false || bIsServerProcess == true );
|
|
// Record server and client frame counts separately, in case they are
|
|
// in the same process.
|
|
static int64 s_lastFrameTime[2];
|
|
|
|
int64 nCurrentFrameTime = GetQPCTime();
|
|
float flElapsedFrameTime = 0.0f;
|
|
if ( s_nRenderFrameCount[bIsServerProcess] )
|
|
{
|
|
flElapsedFrameTime = QPCToMS( nCurrentFrameTime - s_lastFrameTime[bIsServerProcess] );
|
|
}
|
|
|
|
if ( bIsServerProcess )
|
|
{
|
|
EventWriteServerRenderFrameMark( s_nRenderFrameCount[bIsServerProcess], flElapsedFrameTime );
|
|
}
|
|
else
|
|
{
|
|
EventWriteRenderFrameMark( s_nRenderFrameCount[bIsServerProcess], flElapsedFrameTime );
|
|
}
|
|
|
|
++s_nRenderFrameCount[bIsServerProcess];
|
|
s_lastFrameTime[bIsServerProcess] = nCurrentFrameTime;
|
|
}
|
|
|
|
// Insert a simulation frame marker using the Valve-FrameRate provider. Automatically
|
|
// count the frame number and frame time.
|
|
void ETWSimFrameMark( bool bIsServerProcess )
|
|
{
|
|
Assert( bIsServerProcess == false || bIsServerProcess == true );
|
|
// Record server and client frame counts separately, in case they are
|
|
// in the same process.
|
|
static int s_nFrameCount[2];
|
|
static int64 s_lastFrameTime[2];
|
|
|
|
int64 nCurrentFrameTime = GetQPCTime();
|
|
float flElapsedFrameTime = 0.0f;
|
|
if ( s_nFrameCount[bIsServerProcess] )
|
|
{
|
|
flElapsedFrameTime = QPCToMS( nCurrentFrameTime - s_lastFrameTime[bIsServerProcess] );
|
|
}
|
|
|
|
if ( bIsServerProcess )
|
|
{
|
|
EventWriteServerSimFrameMark( s_nFrameCount[bIsServerProcess], flElapsedFrameTime );
|
|
}
|
|
else
|
|
{
|
|
EventWriteSimFrameMark( s_nFrameCount[bIsServerProcess], flElapsedFrameTime );
|
|
}
|
|
|
|
++s_nFrameCount[bIsServerProcess];
|
|
s_lastFrameTime[bIsServerProcess] = nCurrentFrameTime;
|
|
}
|
|
|
|
void ETWMouseDown( int whichButton, int x, int y )
|
|
{
|
|
// Always have x/y first to make the summary tables easier to read.
|
|
EventWriteMouse_down( x, y, whichButton );
|
|
}
|
|
|
|
void ETWMouseUp( int whichButton, int x, int y )
|
|
{
|
|
// Always have x/y first to make the summary tables easier to read.
|
|
EventWriteMouse_up( x, y, whichButton );
|
|
}
|
|
|
|
void ETWMouseMove( int nX, int nY )
|
|
{
|
|
static int lastX, lastY;
|
|
|
|
// Only emit mouse-move events if the mouse position has changed, since
|
|
// otherwise source2 emits a continous stream of events which makes it
|
|
// harder to find 'real' mouse-move events.
|
|
if ( lastX != nX || lastY != nY )
|
|
{
|
|
lastX = nX;
|
|
lastY = nY;
|
|
// Always have x/y first to make the summary tables easier to read.
|
|
EventWriteMouse_Move( nX, nY );
|
|
}
|
|
}
|
|
|
|
void ETWMouseWheel( int nWheelDelta, int nX, int nY )
|
|
{
|
|
// Always have x/y first to make the summary tables easier to read.
|
|
EventWriteMouse_Wheel( nX, nY, nWheelDelta );
|
|
}
|
|
|
|
void ETWKeyDown( int nScanCode, int nVirtualCode, const char *pChar )
|
|
{
|
|
EventWriteKey_down( pChar, nScanCode, nVirtualCode );
|
|
}
|
|
|
|
void ETWSendPacket( const char *pTo, int nWireSize, int nOutSequenceNR, int nOutSequenceNrAck )
|
|
{
|
|
static int s_nCumulativeWireSize;
|
|
s_nCumulativeWireSize += nWireSize;
|
|
|
|
EventWriteSendPacket( pTo, nWireSize, nOutSequenceNR, nOutSequenceNrAck, s_nCumulativeWireSize );
|
|
}
|
|
|
|
void ETWThrottled()
|
|
{
|
|
EventWriteThrottled();
|
|
}
|
|
|
|
void ETWReadPacket( const char *pFrom, int nWireSize, int nInSequenceNR, int nOutSequenceNRAck )
|
|
{
|
|
static int s_nCumulativeWireSize;
|
|
s_nCumulativeWireSize += nWireSize;
|
|
|
|
EventWriteReadPacket( pFrom, nWireSize, nInSequenceNR, nOutSequenceNRAck, s_nCumulativeWireSize );
|
|
}
|
|
|
|
#endif // ETW_MARKS_ENABLED
|