Team Fortress 2 Source Code as on 22/4/2020
You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

377 lines
12 KiB

  1. //============ Copyright (c) Valve Corporation, All rights reserved. ============
  2. //
  3. // ETW (Event Tracing for Windows) profiling helpers.
  4. // This allows easy insertion of Generic Event markers into ETW/xperf tracing
  5. // which then aids in analyzing the traces and finding performance problems.
  6. //
  7. //===============================================================================
  8. #include "pch_tier0.h"
  9. #include "tier0/etwprof.h"
  10. #include <memory>
  11. #ifdef ETW_MARKS_ENABLED
  12. // After building the DLL if it has never been registered on this machine or
  13. // if the providers have changed you need to go:
  14. // xcopy /y %vgame%\bin\tier0.dll %temp%
  15. // wevtutil um %vgame%\..\src\tier0\ValveETWProvider.man
  16. // wevtutil im %vgame%\..\src\tier0\ValveETWProvider.man
  17. #define WIN32_LEAN_AND_MEAN
  18. #include <windows.h>
  19. // These are defined in evntrace.h but you need a Vista+ Windows
  20. // SDK to have them available, so I define them here.
  21. #define EVENT_CONTROL_CODE_DISABLE_PROVIDER 0
  22. #define EVENT_CONTROL_CODE_ENABLE_PROVIDER 1
  23. #define EVENT_CONTROL_CODE_CAPTURE_STATE 2
  24. // EVNTAPI is used in evntprov.h which is included by ValveETWProviderEvents.h
  25. // We define EVNTAPI without the DECLSPEC_IMPORT specifier so that
  26. // we can implement these functions locally instead of using the import library,
  27. // and can therefore still run on Windows XP.
  28. #define EVNTAPI __stdcall
  29. // Include the event register/write/unregister macros compiled from the manifest file.
  30. // Note that this includes evntprov.h which requires a Vista+ Windows SDK
  31. // which we don't currently have, so evntprov.h is checked in.
  32. #include "ValveETWProviderEvents.h"
  33. // Typedefs for use with GetProcAddress
  34. typedef ULONG (__stdcall *tEventRegister)( LPCGUID ProviderId, PENABLECALLBACK EnableCallback, PVOID CallbackContext, PREGHANDLE RegHandle);
  35. typedef ULONG (__stdcall *tEventWrite)( REGHANDLE RegHandle, PCEVENT_DESCRIPTOR EventDescriptor, ULONG UserDataCount, PEVENT_DATA_DESCRIPTOR UserData);
  36. typedef ULONG (__stdcall *tEventUnregister)( REGHANDLE RegHandle );
  37. // Helper class to dynamically load Advapi32.dll, find the ETW functions,
  38. // register the providers if possible, and get the performance counter frequency.
  39. class CETWRegister
  40. {
  41. public:
  42. CETWRegister()
  43. {
  44. QueryPerformanceFrequency( &m_frequency );
  45. // Find Advapi32.dll. This should always succeed.
  46. HMODULE pAdvapiDLL = LoadLibraryW( L"Advapi32.dll" );
  47. if ( pAdvapiDLL )
  48. {
  49. // Try to find the ETW functions. This will fail on XP.
  50. m_pEventRegister = ( tEventRegister )GetProcAddress( pAdvapiDLL, "EventRegister" );
  51. m_pEventWrite = ( tEventWrite )GetProcAddress( pAdvapiDLL, "EventWrite" );
  52. m_pEventUnregister = ( tEventUnregister )GetProcAddress( pAdvapiDLL, "EventUnregister" );
  53. // Register two ETW providers. If registration fails then the event logging calls will fail.
  54. // On XP these calls will do nothing.
  55. // On Vista and above, if these providers have been enabled by xperf or logman then
  56. // the VALVE_FRAMERATE_Context and VALVE_MAIN_Context globals will be modified
  57. // like this:
  58. // MatchAnyKeyword: 0xffffffffffffffff
  59. // IsEnabled: 1
  60. // Level: 255
  61. // In other words, fully enabled.
  62. EventRegisterValve_FrameRate();
  63. EventRegisterValve_ServerFrameRate();
  64. EventRegisterValve_Main();
  65. EventRegisterValve_Input();
  66. EventRegisterValve_Network();
  67. // Emit the thread ID for the main thread. This also indicates that
  68. // the main provider is initialized.
  69. EventWriteThread_ID( GetCurrentThreadId(), "Main thread" );
  70. // Emit an input system event so we know that it is active.
  71. EventWriteKey_down( "Valve input provider initialized.", 0, 0 );
  72. }
  73. }
  74. ~CETWRegister()
  75. {
  76. // Unregister our providers.
  77. EventUnregisterValve_Network();
  78. EventUnregisterValve_Input();
  79. EventUnregisterValve_Main();
  80. EventUnregisterValve_ServerFrameRate();
  81. EventUnregisterValve_FrameRate();
  82. }
  83. tEventRegister m_pEventRegister;
  84. tEventWrite m_pEventWrite;
  85. tEventUnregister m_pEventUnregister;
  86. // QPC frequency
  87. LARGE_INTEGER m_frequency;
  88. } g_ETWRegister;
  89. // Redirector function for EventRegister. Called by macros in ValveETWProviderEvents.h
  90. ULONG EVNTAPI EventRegister( LPCGUID ProviderId, PENABLECALLBACK EnableCallback, PVOID CallbackContext, PREGHANDLE RegHandle )
  91. {
  92. if ( g_ETWRegister.m_pEventRegister )
  93. return g_ETWRegister.m_pEventRegister( ProviderId, EnableCallback, CallbackContext, RegHandle );
  94. return 0;
  95. }
  96. // Redirector function for EventWrite. Called by macros in ValveETWProviderEvents.h
  97. ULONG EVNTAPI EventWrite( REGHANDLE RegHandle, PCEVENT_DESCRIPTOR EventDescriptor, ULONG UserDataCount, PEVENT_DATA_DESCRIPTOR UserData )
  98. {
  99. if ( g_ETWRegister.m_pEventWrite )
  100. return g_ETWRegister.m_pEventWrite( RegHandle, EventDescriptor, UserDataCount, UserData );
  101. return 0;
  102. }
  103. // Redirector function for EventUnregister. Called by macros in ValveETWProviderEvents.h
  104. ULONG EVNTAPI EventUnregister( REGHANDLE RegHandle )
  105. {
  106. if ( g_ETWRegister.m_pEventUnregister )
  107. return g_ETWRegister.m_pEventUnregister( RegHandle );
  108. return 0;
  109. }
  110. // Call QueryPerformanceCounter
  111. static int64 GetQPCTime()
  112. {
  113. LARGE_INTEGER time;
  114. QueryPerformanceCounter( &time );
  115. return time.QuadPart;
  116. }
  117. // Convert a QueryPerformanceCounter delta into milliseconds
  118. static float QPCToMS( int64 nDelta )
  119. {
  120. // Convert from a QPC delta to seconds.
  121. float flSeconds = ( float )( nDelta / double( g_ETWRegister.m_frequency.QuadPart ) );
  122. // Convert from seconds to milliseconds
  123. return flSeconds * 1000;
  124. }
  125. // Public functions for emitting ETW events.
  126. int64 ETWMark( const char *pMessage )
  127. {
  128. int64 nTime = GetQPCTime();
  129. EventWriteMark( pMessage );
  130. return nTime;
  131. }
  132. int64 ETWMarkPrintf( const char *pMessage, ... )
  133. {
  134. // If we are running on Windows XP or if our providers have not been enabled
  135. // (by xperf or other) then this will be false and we can early out.
  136. // Be sure to check the appropriate context for the event. This is only
  137. // worth checking if there is some cost beyond the EventWrite that we can
  138. // avoid -- the redirectors in this file guarantee that EventWrite is always
  139. // safe to call.
  140. if ( !VALVE_MAIN_Context.IsEnabled )
  141. {
  142. return 0;
  143. }
  144. char buffer[1000];
  145. va_list args;
  146. va_start( args, pMessage );
  147. vsprintf_s( buffer, pMessage, args );
  148. va_end( args );
  149. int64 nTime = GetQPCTime();
  150. EventWriteMark( buffer );
  151. return nTime;
  152. }
  153. void ETWMark1F( const char *pMessage, float data1 )
  154. {
  155. EventWriteMark1F( pMessage, data1 );
  156. }
  157. void ETWMark2F( const char *pMessage, float data1, float data2 )
  158. {
  159. EventWriteMark2F( pMessage, data1, data2 );
  160. }
  161. void ETWMark3F( const char *pMessage, float data1, float data2, float data3 )
  162. {
  163. EventWriteMark3F( pMessage, data1, data2, data3 );
  164. }
  165. void ETWMark4F( const char *pMessage, float data1, float data2, float data3, float data4 )
  166. {
  167. EventWriteMark4F( pMessage, data1, data2, data3, data4 );
  168. }
  169. void ETWMark1I( const char *pMessage, int data1 )
  170. {
  171. EventWriteMark1I( pMessage, data1 );
  172. }
  173. void ETWMark2I( const char *pMessage, int data1, int data2 )
  174. {
  175. EventWriteMark2I( pMessage, data1, data2 );
  176. }
  177. void ETWMark3I( const char *pMessage, int data1, int data2, int data3 )
  178. {
  179. EventWriteMark3I( pMessage, data1, data2, data3 );
  180. }
  181. void ETWMark4I( const char *pMessage, int data1, int data2, int data3, int data4 )
  182. {
  183. EventWriteMark4I( pMessage, data1, data2, data3, data4 );
  184. }
  185. void ETWMark1S( const char *pMessage, const char* data1 )
  186. {
  187. EventWriteMark1S( pMessage, data1 );
  188. }
  189. void ETWMark2S( const char *pMessage, const char* data1, const char* data2 )
  190. {
  191. EventWriteMark2S( pMessage, data1, data2 );
  192. }
  193. // Track the depth of ETW Begin/End pairs. This needs to be per-thread
  194. // if we start emitting marks on multiple threads. Using __declspec(thread)
  195. // has some problems on Windows XP, but since these ETW functions only work
  196. // on Vista+ that doesn't matter.
  197. static __declspec( thread ) int s_nDepth;
  198. int64 ETWBegin( const char *pMessage )
  199. {
  200. // If we are running on Windows XP or if our providers have not been enabled
  201. // (by xperf or other) then this will be false and we can early out.
  202. // Be sure to check the appropriate context for the event. This is only
  203. // worth checking if there is some cost beyond the EventWrite that we can
  204. // avoid -- the redirectors in this file guarantee that EventWrite is always
  205. // safe to call.
  206. // In this case we also avoid the potentially unreliable TLS implementation
  207. // (for dynamically loaded DLLs) on Windows XP.
  208. if ( !VALVE_MAIN_Context.IsEnabled )
  209. {
  210. return 0;
  211. }
  212. int64 nTime = GetQPCTime();
  213. EventWriteStart( pMessage, s_nDepth++ );
  214. return nTime;
  215. }
  216. int64 ETWEnd( const char *pMessage, int64 nStartTime )
  217. {
  218. // If we are running on Windows XP or if our providers have not been enabled
  219. // (by xperf or other) then this will be false and we can early out.
  220. // Be sure to check the appropriate context for the event. This is only
  221. // worth checking if there is some cost beyond the EventWrite that we can
  222. // avoid -- the redirectors in this file guarantee that EventWrite is always
  223. // safe to call.
  224. // In this case we also avoid the potentially unreliable TLS implementation
  225. // (for dynamically loaded DLLs) on Windows XP.
  226. if ( !VALVE_MAIN_Context.IsEnabled )
  227. {
  228. return 0;
  229. }
  230. int64 nTime = GetQPCTime();
  231. EventWriteStop( pMessage, --s_nDepth, QPCToMS( nTime - nStartTime ) );
  232. return nTime;
  233. }
  234. static int s_nRenderFrameCount;
  235. int ETWGetRenderFrameNumber()
  236. {
  237. return s_nRenderFrameCount;
  238. }
  239. // Insert a render frame marker using the Valve-FrameRate provider. Automatically
  240. // count the frame number and frame time. Since the frame count and elapsed time
  241. // are tracked without paying attention to the bIsServerProcess flag the results
  242. // will be 'unexpected' if bIsServerProcess changes value within a process.
  243. void ETWRenderFrameMark( bool bIsServerProcess )
  244. {
  245. static int64 s_lastFrameTime;
  246. int64 nCurrentFrameTime = GetQPCTime();
  247. float flElapsedFrameTime = 0.0f;
  248. if ( s_nRenderFrameCount )
  249. {
  250. flElapsedFrameTime = QPCToMS( nCurrentFrameTime - s_lastFrameTime );
  251. }
  252. if ( bIsServerProcess )
  253. {
  254. EventWriteServerRenderFrameMark( s_nRenderFrameCount, flElapsedFrameTime );
  255. }
  256. else
  257. {
  258. EventWriteRenderFrameMark( s_nRenderFrameCount, flElapsedFrameTime );
  259. }
  260. ++s_nRenderFrameCount;
  261. s_lastFrameTime = nCurrentFrameTime;
  262. }
  263. // Insert a simulation frame marker using the Valve-FrameRate provider. Automatically
  264. // count the frame number and frame time. Since the frame count and elapsed time
  265. // are tracked without paying attention to the bIsServerProcess flag the results
  266. // will be 'unexpected' if bIsServerProcess changes value within a process.
  267. void ETWSimFrameMark( bool bIsServerProcess )
  268. {
  269. static int s_nFrameCount;
  270. static int64 s_lastFrameTime;
  271. int64 nCurrentFrameTime = GetQPCTime();
  272. float flElapsedFrameTime = 0.0f;
  273. if ( s_nFrameCount )
  274. {
  275. flElapsedFrameTime = QPCToMS( nCurrentFrameTime - s_lastFrameTime );
  276. }
  277. if ( bIsServerProcess )
  278. {
  279. EventWriteServerSimFrameMark( s_nFrameCount, flElapsedFrameTime );
  280. }
  281. else
  282. {
  283. EventWriteSimFrameMark( s_nFrameCount, flElapsedFrameTime );
  284. }
  285. ++s_nFrameCount;
  286. s_lastFrameTime = nCurrentFrameTime;
  287. }
  288. void ETWMouseDown( int whichButton, int x, int y )
  289. {
  290. EventWriteMouse_down( whichButton, x, y );
  291. }
  292. void ETWMouseUp( int whichButton, int x, int y )
  293. {
  294. EventWriteMouse_up( whichButton, x, y );
  295. }
  296. void ETWKeyDown( int nScanCode, int nVirtualCode, const char *pChar )
  297. {
  298. EventWriteKey_down( pChar, nScanCode, nVirtualCode );
  299. }
  300. void ETWSendPacket( const char *pTo, int nWireSize, int nOutSequenceNR, int nOutSequenceNrAck )
  301. {
  302. static int s_nCumulativeWireSize;
  303. s_nCumulativeWireSize += nWireSize;
  304. EventWriteSendPacket( pTo, nWireSize, nOutSequenceNR, nOutSequenceNrAck, s_nCumulativeWireSize );
  305. }
  306. void ETWThrottled()
  307. {
  308. EventWriteThrottled();
  309. }
  310. void ETWReadPacket( const char *pFrom, int nWireSize, int nInSequenceNR, int nOutSequenceNRAck )
  311. {
  312. static int s_nCumulativeWireSize;
  313. s_nCumulativeWireSize += nWireSize;
  314. EventWriteReadPacket( pFrom, nWireSize, nInSequenceNR, nOutSequenceNRAck, s_nCumulativeWireSize );
  315. }
  316. #endif // ETW_MARKS_ENABLED