#include #include #include extern "C" { #include "profiling.h" } #pragma warning(disable:4786) #include #include #include #include #include class CProfiling { typedef std::map PROFILE_ENRTIES; typedef PROFILE_ENRTIES::iterator PROFILE_ENRTY; typedef PROFILE_ENRTIES::value_type PROFILE_VALUE; typedef struct { SPECIAL_TIMERS Timer; char * Name; } TIMER_NAME; DWORD m_CurrentTimerAddr, CurrentDisplayCount; DWORD m_StartTimeHi, m_StartTimeLo; // The current timer start time PROFILE_ENRTIES m_Entries; public: CProfiling () { m_CurrentTimerAddr = Timer_None; } // Recording timing against current timer, returns the address of the timer stopped DWORD StartTimer ( DWORD Address ) { DWORD OldTimerAddr = StopTimer(); m_CurrentTimerAddr = Address; #if defined(_M_IX86) && defined(_MSC_VER) DWORD HiValue, LoValue; _asm { pushad rdtsc mov HiValue, edx mov LoValue, eax popad } m_StartTimeHi = HiValue; m_StartTimeLo = LoValue; #else DebugBreak(); #endif return OldTimerAddr; } DWORD StopTimer ( void ) { if (m_CurrentTimerAddr == Timer_None) { return m_CurrentTimerAddr; } #if defined(_M_IX86) && defined(_MSC_VER) DWORD HiValue, LoValue; _asm { pushad rdtsc mov HiValue, edx mov LoValue, eax popad } __int64 StopTime = ((unsigned __int64)HiValue << 32) + (unsigned __int64)LoValue; __int64 StartTime = ((unsigned __int64)m_StartTimeHi << 32) + (unsigned __int64)m_StartTimeLo; __int64 TimeTaken = StopTime - StartTime; PROFILE_ENRTY Entry = m_Entries.find(m_CurrentTimerAddr); if (Entry != m_Entries.end()) { Entry->second += TimeTaken; } else { m_Entries.insert(PROFILE_ENRTIES::value_type(m_CurrentTimerAddr, TimeTaken)); } #else DebugBreak(); #endif DWORD OldTimerAddr = m_CurrentTimerAddr; m_CurrentTimerAddr = Timer_None; return OldTimerAddr; } // Reset all the counters back to 0 void ResetCounters ( void ) { m_Entries.clear(); } // Generate a log file with the current results, this will also reset the counters void GenerateLog ( void ) { stdstr LogFileName; { CLog Log; Log.Open("RSP Profiling.txt"); LogFileName = Log.FileName(); // Get the total time __int64 TotalTime = 0; for (PROFILE_ENRTY itemTime = m_Entries.begin(); itemTime != m_Entries.end(); itemTime++ ) { TotalTime += itemTime->second; } // Create a sortable list of items std::vector ItemList; for (PROFILE_ENRTY Entry = m_Entries.begin(); Entry != m_Entries.end(); Entry++ ) { ItemList.push_back(&(*Entry)); } // Sort the list with a basic bubble sort if (ItemList.size() > 0) { for (size_t OuterPass = 0; OuterPass < (ItemList.size() - 1); OuterPass++ ) { for (size_t InnerPass = 0; InnerPass < (ItemList.size() - 1); InnerPass++ ) { if (ItemList[InnerPass]->second < ItemList[InnerPass + 1]->second) { PROFILE_VALUE * TempPtr = ItemList[InnerPass]; ItemList[InnerPass] = ItemList[InnerPass + 1]; ItemList[InnerPass + 1] = TempPtr; } } } } TIMER_NAME TimerNames[] = { {Timer_Compiling, "RSP: Compiling"}, {Timer_RSP_Running, "RSP: Running"}, {Timer_R4300_Running, "R4300i: Running"}, {Timer_RDP_Running, "RDP: Running"}, }; for (size_t count = 0; count < ItemList.size(); count++ ) { char Buffer[255]; float CpuUsage = (float)(((double)ItemList[count]->second / (double)TotalTime) * 100); if (CpuUsage <= 0.2) { continue; } sprintf(Buffer, "Func 0x%08X", ItemList[count]->first); for (int NameID = 0; NameID < (sizeof(TimerNames) / sizeof(TIMER_NAME)); NameID++) { if (ItemList[count]->first == (DWORD)TimerNames[NameID].Timer) { strcpy(Buffer,TimerNames[NameID].Name); break; } } Log.LogF("%s\t%2.2f",Buffer, CpuUsage); } } ShellExecute(NULL,"open",LogFileName.c_str(),NULL,NULL,SW_SHOW); ResetCounters(); } }; CProfiling& GetProfiler ( void ) { static CProfiling Profile; return Profile; } void ResetTimerList (void) { GetProfiler().ResetCounters(); } DWORD StartTimer (DWORD Address) { return GetProfiler().StartTimer(Address); } void StopTimer (void) { GetProfiler().StopTimer(); } void GenerateTimerResults (void) { GetProfiler().GenerateLog(); } #ifdef todelete #include #include typedef struct { char Label[100]; __int64 TimeTotal; } TIME_STAMP_ENTRY; DWORD StartTimeHi, StartTimeLo, StopTimeHi, StopTimeLo, TSE_Count, TSE_Max; TIME_STAMP_ENTRY * TS_Entries = NULL; char LastLabel[100]; void ResetTimerList (void) { if (TS_Entries) { free(TS_Entries); } TS_Entries = NULL; TSE_Count = 0; TSE_Max = 0; } void StartTimer (char * Label) { strcpy(LastLabel,Label); _asm { pushad rdtsc mov StartTimeHi, edx mov StartTimeLo, eax popad } } void StopTimer (void) { _asm { pushad rdtsc mov StopTimeHi, edx mov StopTimeLo, eax popad } if (strlen(LastLabel) == 0) { return; } { DWORD count; for (count = 0; count < TSE_Count; count ++) { if (strcmp(LastLabel,TS_Entries[count].Label) == 0) { __int64 Time = ((unsigned __int64)StopTimeHi << 32) + (unsigned __int64)StopTimeLo; Time -= ((unsigned __int64)StartTimeHi << 32) + (unsigned __int64)StartTimeLo; TS_Entries[count].TimeTotal += Time; return; } } } if (TSE_Count == 0) { TS_Entries = (TIME_STAMP_ENTRY *)malloc(sizeof(TIME_STAMP_ENTRY) * 100); if (TS_Entries == NULL) { MessageBox(NULL,"TIME_STAMP_ENTRY == NULL ??","ERROR",MB_OK|MB_ICONERROR|MB_SETFOREGROUND); } TSE_Max = 100; } else if (TSE_Count == TSE_Max) { TSE_Max += 100; TS_Entries = (TIME_STAMP_ENTRY *)realloc(TS_Entries,sizeof(TIME_STAMP_ENTRY) * TSE_Max); if (TS_Entries == NULL) { MessageBox(NULL,"TIME_STAMP_ENTRY == NULL ??","ERROR",MB_OK|MB_ICONERROR|MB_SETFOREGROUND); } } strcpy(TS_Entries[TSE_Count].Label,LastLabel); TS_Entries[TSE_Count].TimeTotal = ((unsigned __int64)StopTimeHi << 32) + (unsigned __int64)StopTimeLo; TS_Entries[TSE_Count].TimeTotal -= ((unsigned __int64)StartTimeHi << 32) + (unsigned __int64)StartTimeLo; TSE_Count +=1; } void GenerateTimerResults (void) { char buffer[_MAX_PATH], drive[_MAX_DRIVE] ,dir[_MAX_DIR]; char fname[_MAX_FNAME],ext[_MAX_EXT], LogFileName[_MAX_PATH]; DWORD dwWritten, count, count2; HANDLE hLogFile = NULL; __int64 TotalTime; StopTimer(); GetModuleFileName(NULL,buffer,sizeof(buffer)); _splitpath( buffer, drive, dir, fname, ext ); _makepath( LogFileName, drive, dir, "RSP Profiling", "log" ); hLogFile = CreateFile(LogFileName,GENERIC_WRITE, FILE_SHARE_READ|FILE_SHARE_WRITE,NULL, CREATE_ALWAYS,FILE_ATTRIBUTE_NORMAL | FILE_FLAG_SEQUENTIAL_SCAN, NULL); SetFilePointer(hLogFile,0,NULL,FILE_BEGIN); for (count = 0; count < TSE_Count; count ++) { for (count2 = 0; count2 < (TSE_Count - 1); count2 ++) { if (TS_Entries[count2].TimeTotal < TS_Entries[count2 + 1].TimeTotal) { TIME_STAMP_ENTRY Temp; memcpy(&Temp,&TS_Entries[count2],sizeof(TIME_STAMP_ENTRY)); memcpy(&TS_Entries[count2],&TS_Entries[count2 + 1],sizeof(TIME_STAMP_ENTRY)); memcpy(&TS_Entries[count2 + 1],&Temp,sizeof(TIME_STAMP_ENTRY)); } } } TotalTime = 0; for (count = 0; count < TSE_Count; count ++) { TotalTime += TS_Entries[count].TimeTotal; } for (count = 0; count < (TSE_Count < 50?TSE_Count:50); count ++) { sprintf(buffer,"%s - %0.2f%c\r\n", TS_Entries[count].Label, (((double)TS_Entries[count].TimeTotal / (double)TotalTime) * 100),'%' ); WriteFile( hLogFile,buffer,strlen(buffer),&dwWritten,NULL ); } CloseHandle(hLogFile); ResetTimerList(); } #endif