ShuriZma
/
project64
mirror of https://github.com/project64/project64.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

[Project64] Add Profiling

This commit is contained in:
zilmar 2016-10-03 08:46:05 +11:00
parent 967ed96a8b
commit fd69ab6b18
24 changed files with 224 additions and 236 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

8
Android/res/menu/game_activity.xml
View File

@ -31,6 +31,14 @@
<item
android:id="@+id/menuItem_settings"
android:title="@string/menuItem_settings"/>
<item
android:id="@+id/menuItem_DebuggingMenu"
android:title="@string/menuItem_DebuggingOptions">
<menu>
<item android:id="@+id/menuItem_ResetFunctionTimes" android:title="@string/menuItem_ResetFunctionTimes" />
<item android:id="@+id/menuItem_DumpFunctionTimes" android:title="@string/menuItem_DumpFunctionTimes" />
</menu>
</item>
<item
android:id="@+id/menuItem_pause"
android:title="@string/menuItem_pause"/>

5
Android/res/values/strings.xml
View File

@ -19,6 +19,9 @@
<string name="menuItem_CurrentSave9">Slot 9</string>
<string name="menuItem_CurrentSave10">Slot 10</string>
<string name="menuItem_ConsoleReset">Reset</string>
<string name="menuItem_DebuggingOptions">Debugging Options</string>
<string name="menuItem_ResetFunctionTimes">Reset Function Times</string>
<string name="menuItem_DumpFunctionTimes">Dump Function Times</string>
<!-- Menu Activity -->
<string name="menuItem_search">Search</string>
@ -167,6 +170,8 @@
<string name="DListPerSecond">Display lists per second</string>
<string name="PercentageOfSpeed">Percentage of full speed</string>
<string name="VerticalInterruptsPerSecond">Vertical interrupts per second</string>
<string name="RecordExecutionTimes_title">Record Execution Times</string>
<string name="RecordExecutionTimes_summary">Record how long each block executes for</string>
<string name="ForceGfxReset_title">Reset GFX Plugin</string>
<string name="ForceGfxReset_summary">Always reload GFX plugin</string>
<string name="touchscreenScale_title">Button scale</string>

4
Android/res/xml/settings_advanced.xml
View File

@ -22,6 +22,10 @@
android:key="Debugger_CpuUsage"
android:summary="@string/CpuUsage_summary"
android:title="@string/CpuUsage_title" />
<CheckBoxPreference
android:key="Debugger_RecordExecutionTimes"
android:summary="@string/RecordExecutionTimes_summary"
android:title="@string/RecordExecutionTimes_title" />
<CheckBoxPreference
android:key="Plugin_ForceGfxReset"
android:summary="@string/ForceGfxReset_summary"

19
Android/src/emu/project64/game/GameMenuHandler.java
View File

@ -48,6 +48,13 @@ public class GameMenuHandler implements PopupMenu.OnMenuItemClickListener, Popup
public void onClick(View view)
{
Boolean GamePaused = NativeExports.SettingsLoadBool(SettingsID.GameRunning_CPU_Paused.getValue());
Boolean RecordExecutionTimes = NativeExports.SettingsLoadBool(SettingsID.Debugger_RecordExecutionTimes.getValue());
Boolean ShowDebugMenu = NativeExports.SettingsLoadBool(SettingsID.Debugger_Enabled.getValue());
if (!RecordExecutionTimes)
{
ShowDebugMenu = false;
}
NativeExports.ExternalEvent( SystemEvent.SysEvent_PauseCPU_AppLostActive.getValue());
@ -61,7 +68,10 @@ public class GameMenuHandler implements PopupMenu.OnMenuItemClickListener, Popup
menu.findItem(R.id.menuItem_pause).setVisible(GamePaused ? false : true);
menu.findItem(R.id.menuItem_resume).setVisible(GamePaused ? true : false);
menu.findItem(R.id.menuItem_ResetFunctionTimes).setVisible(RecordExecutionTimes);
menu.findItem(R.id.menuItem_DumpFunctionTimes).setVisible(RecordExecutionTimes);
menu.findItem(R.id.menuItem_DebuggingMenu).setVisible(ShowDebugMenu);
String SaveDirectory = NativeExports.SettingsLoadString(SettingsID.Directory_InstantSave.getValue());
if ( NativeExports.SettingsLoadBool(SettingsID.Setting_UniqueSaveDir.getValue()))
{
@ -89,6 +99,7 @@ public class GameMenuHandler implements PopupMenu.OnMenuItemClickListener, Popup
switch (item.getItemId())
{
case R.id.menuItem_CurrentSaveState:
case R.id.menuItem_DebuggingMenu:
mOpeningSubmenu = true;
break;
case R.id.menuItem_SaveState:
@ -139,6 +150,12 @@ public class GameMenuHandler implements PopupMenu.OnMenuItemClickListener, Popup
case R.id.menuItem_HardReset:
NativeExports.ExternalEvent( SystemEvent.SysEvent_ResetCPU_Hard.getValue());
break;
case R.id.menuItem_ResetFunctionTimes:
NativeExports.ExternalEvent( SystemEvent.SysEvent_ResetFunctionTimes.getValue());
break;
case R.id.menuItem_DumpFunctionTimes:
NativeExports.ExternalEvent( SystemEvent.SysEvent_DumpFunctionTimes.getValue());
break;
case R.id.menuItem_EndEmulation:
NativeExports.ExternalEvent( SystemEvent.SysEvent_ResumeCPU_FromMenu.getValue());
mLifecycleHandler.AutoSave();

1
Android/src/emu/project64/jni/SettingsID.java
View File

@ -216,6 +216,7 @@ public enum SettingsID
Debugger_ShowDListAListCount,
Debugger_ShowRecompMemSize,
Debugger_DebugLanguage,
Debugger_RecordExecutionTimes,
//Trace
Debugger_TraceMD5,

3
Android/src/emu/project64/jni/SystemEvent.java
View File

@ -49,7 +49,8 @@ public enum SystemEvent
SysEvent_Interrupt_DP,
SysEvent_Profile_StartStop,
SysEvent_Profile_ResetLogs,
SysEvent_Profile_GenerateLogs
SysEvent_ResetFunctionTimes,
SysEvent_DumpFunctionTimes,
;
private int value;

2
Android/src/emu/project64/settings/SettingsActivity.java
View File

@ -61,6 +61,7 @@ public class SettingsActivity extends AppCompatActivity implements SharedPrefere
.putBoolean("Debugger_LimitFPS",NativeExports.SettingsLoadBool(SettingsID.GameRunning_LimitFPS.getValue()))
.putBoolean("Debugger_DisplaySpeed",NativeExports.SettingsLoadBool(SettingsID.UserInterface_DisplayFrameRate.getValue()))
.putBoolean("Debugger_CpuUsage",NativeExports.SettingsLoadBool(SettingsID.UserInterface_ShowCPUPer.getValue()))
.putBoolean("Debugger_RecordExecutionTimes",NativeExports.SettingsLoadBool(SettingsID.Debugger_RecordExecutionTimes.getValue()))
.putString("Debugger_DisplaySpeedType",String.valueOf(NativeExports.SettingsLoadDword(SettingsID.UserInterface_FrameDisplayType.getValue())))
.putString("Debugger_TraceMD5",String.valueOf(NativeExports.SettingsLoadDword(SettingsID.Debugger_TraceMD5.getValue())))
.putString("Debugger_TraceThread",String.valueOf(NativeExports.SettingsLoadDword(SettingsID.Debugger_TraceThread.getValue())))
@ -131,6 +132,7 @@ public class SettingsActivity extends AppCompatActivity implements SharedPrefere
else if (key.equals("Debugger_Enabled")) { NativeExports.SettingsSaveBool(SettingsID.Debugger_Enabled.getValue(), sharedPreferences.getBoolean(key,false)); }
else if (key.equals("Debugger_GenerateLogFiles")) { NativeExports.SettingsSaveBool(SettingsID.Debugger_GenerateLogFiles.getValue(), sharedPreferences.getBoolean(key,false)); }
else if (key.equals("Debugger_CpuUsage")) { NativeExports.SettingsSaveBool(SettingsID.UserInterface_ShowCPUPer.getValue(), sharedPreferences.getBoolean(key,false)); }
else if (key.equals("Debugger_RecordExecutionTimes")) { NativeExports.SettingsSaveBool(SettingsID.Debugger_RecordExecutionTimes.getValue(), sharedPreferences.getBoolean(key,false)); }
else if (key.equals("Debugger_LimitFPS")) { NativeExports.SettingsSaveBool(SettingsID.GameRunning_LimitFPS.getValue(), sharedPreferences.getBoolean(key,false)); }
else if (key.equals("Debugger_DisplaySpeed")) { NativeExports.SettingsSaveBool(SettingsID.UserInterface_DisplayFrameRate.getValue(), sharedPreferences.getBoolean(key,false)); }
else if (key.equals("Debugger_DisplaySpeedType")) { NativeExports.SettingsSaveDword(SettingsID.UserInterface_FrameDisplayType.getValue(), Integer.valueOf(sharedPreferences.getString(key, "0"))); }

1
Source/Project64-core/N64System/Mips/Mempak.cpp
View File

@ -20,7 +20,6 @@ void CMempak::LoadMempak(int32_t Control)
MempakName.Format("%s_Cont_%d", g_Settings->LoadStringVal(Game_GameName).c_str(), Control + 1);
CPath MempakPath(g_Settings->LoadStringVal(Directory_NativeSave).c_str(), stdstr_f("%s.mpk", MempakName.c_str()).c_str());
if (g_Settings->LoadBool(Setting_UniqueSaveDir))
{
MempakPath.AppendDirectory(g_Settings->LoadStringVal(Game_UniqueSaveDir).c_str());

14
Source/Project64-core/N64System/Mips/SystemEvents.cpp
View File

@ -71,12 +71,12 @@ void CSystemEvents::ExecuteEvents()
case SysEvent_ResetCPU_Hard:
m_System->Reset(true, true);
break;
case SysEvent_Profile_GenerateLogs:
m_System->m_Profile.GenerateLog();
break;
case SysEvent_Profile_StartStop:
case SysEvent_Profile_ResetLogs:
m_System->m_Profile.ResetCounters();
if (g_Recompiler)
{
g_Recompiler->ResetFunctionTimes();
}
break;
case SysEvent_ExecuteInterrupt:
g_Reg->DoIntrException(false);
@ -121,6 +121,12 @@ void CSystemEvents::ExecuteEvents()
case SysEvent_ChangePlugins:
ChangePluginFunc();
break;
case SysEvent_DumpFunctionTimes:
if (g_Recompiler)
{
g_Recompiler->DumpFunctionTimes();
}
break;
case SysEvent_ChangingFullScreen:
g_Notify->ChangeFullScreen();
break;

3
Source/Project64-core/N64System/Mips/SystemEvents.h
View File

@ -51,7 +51,8 @@ enum SystemEvent
SysEvent_Interrupt_DP,
SysEvent_Profile_StartStop,
SysEvent_Profile_ResetLogs,
SysEvent_Profile_GenerateLogs,
SysEvent_ResetFunctionTimes,
SysEvent_DumpFunctionTimes,
};
class CN64System;

53
Source/Project64-core/N64System/N64Class.cpp
View File

@ -95,7 +95,7 @@ CN64System::CN64System(CPlugins * Plugins, bool SavesReadOnly, bool SyncSystem)
if (CpuType == CPU_Recompiler || CpuType == CPU_SyncCores)
{
m_Recomp = new CRecompiler(m_Reg, m_Profile, m_EndEmulation);
m_Recomp = new CRecompiler(m_Reg, m_EndEmulation);
}
}
WriteTrace(TraceN64System, TraceDebug, "Done");
@ -149,7 +149,6 @@ void CN64System::ExternalEvent(SystemEvent action)
switch (action)
{
case SysEvent_Profile_GenerateLogs:
case SysEvent_Profile_StartStop:
case SysEvent_Profile_ResetLogs:
case SysEvent_ExecuteInterrupt:
@ -169,6 +168,7 @@ void CN64System::ExternalEvent(SystemEvent action)
case SysEvent_CloseCPU:
case SysEvent_ChangePlugins:
case SysEvent_PauseCPU_FromMenu:
case SysEvent_DumpFunctionTimes:
QueueEvent(action);
break;
case SysEvent_PauseCPU_AppLostFocus:
@ -1892,9 +1892,11 @@ bool CN64System::LoadState(const char * FileName)
WriteTrace(TraceN64System, TraceDebug, "5");
m_TLB.Reset(false);
WriteTrace(TraceN64System, TraceDebug, "6");
m_CPU_Usage.ResetCounters();
WriteTrace(TraceN64System, TraceDebug, "7");
m_Profile.ResetCounters();
if (m_Recomp)
{
m_Recomp->ResetFunctionTimes();
}
m_CPU_Usage.ResetTimers();
WriteTrace(TraceN64System, TraceDebug, "8");
m_FPS.Reset(true);
WriteTrace(TraceN64System, TraceDebug, "9");
@ -1943,7 +1945,7 @@ void CN64System::RunRSP()
{
if ((m_Reg.SP_STATUS_REG & SP_STATUS_BROKE) == 0)
{
SPECIAL_TIMERS CPU_UsageAddr = Timer_None/*, ProfileAddr = Timer_None*/;
HighResTimeStamp StartTime;
uint32_t Task = 0;
if (m_RspBroke)
@ -1976,14 +1978,9 @@ void CN64System::RunRSP()
{
DisplayRSPListCount();
}
if (bShowCPUPer())
if (bRecordExecutionTimes() || bShowCPUPer())
{
switch (Task)
{
case 1: CPU_UsageAddr = m_CPU_Usage.StartTimer(Timer_RSP_Dlist); break;
case 2: CPU_UsageAddr = m_CPU_Usage.StartTimer(Timer_RSP_Alist); break;
default: CPU_UsageAddr = m_CPU_Usage.StartTimer(Timer_RSP_Unknown); break;
}
StartTime.SetToNow();
}
}
@ -2004,8 +2001,22 @@ void CN64System::RunRSP()
g_SystemTimer->SetTimer(CSystemTimer::RSPTimerDlist, 0x1000, false);
m_Reg.m_GfxIntrReg &= ~MI_INTR_DP;
}
if (bShowCPUPer()) { m_CPU_Usage.StartTimer(CPU_UsageAddr); }
//if (bProfiling) { m_Profile.StartTimer(ProfileAddr); }
if (bRecordExecutionTimes() || bShowCPUPer())
{
HighResTimeStamp EndTime;
EndTime.SetToNow();
uint32_t TimeTaken = (uint32_t)(EndTime.GetMicroSeconds() - StartTime.GetMicroSeconds());
if (bShowCPUPer())
{
switch (Task)
{
case 1: m_CPU_Usage.RecordTime(Timer_RSP_Dlist, TimeTaken); break;
case 2: m_CPU_Usage.RecordTime(Timer_RSP_Alist, TimeTaken); break;
default: m_CPU_Usage.RecordTime(Timer_RSP_Unknown, TimeTaken); break;
}
}
}
if ((m_Reg.SP_STATUS_REG & SP_STATUS_HALT) == 0 &&
(m_Reg.SP_STATUS_REG & SP_STATUS_BROKE) == 0 &&
@ -2031,9 +2042,11 @@ void CN64System::SyncToAudio()
{
return;
}
SPECIAL_TIMERS CPU_UsageAddr = Timer_None;
if (bShowCPUPer()) { CPU_UsageAddr = m_CPU_Usage.StartTimer(Timer_Idel); }
PROFILE_TIMERS PreviousTimer = Timer_None;
if (bShowCPUPer())
{
PreviousTimer = m_CPU_Usage.StartTimer(Timer_Idel);
}
for (int i = 0; i < 50; i++)
{
@ -2046,13 +2059,13 @@ void CN64System::SyncToAudio()
}
if (bShowCPUPer())
{
m_CPU_Usage.StartTimer(CPU_UsageAddr != Timer_None ? CPU_UsageAddr : Timer_R4300);
m_CPU_Usage.StartTimer(PreviousTimer);
}
}
void CN64System::RefreshScreen()
{
SPECIAL_TIMERS CPU_UsageAddr = Timer_None/*, ProfilingAddr = Timer_None*/;
PROFILE_TIMERS CPU_UsageAddr = Timer_None/*, ProfilingAddr = Timer_None*/;
uint32_t VI_INTR_TIME = 500000;
if (bShowCPUPer()) { CPU_UsageAddr = m_CPU_Usage.StartTimer(Timer_RefreshScreen); }

1
Source/Project64-core/N64System/N64Class.h
View File

@ -51,7 +51,6 @@ public:
CN64System(CPlugins * Plugins, bool SavesReadOnly, bool SyncSystem);
virtual ~CN64System(void);
CProfiling m_Profile;
CCheats m_Cheats;
bool m_EndEmulation;
SAVE_CHIP_TYPE m_SaveUsing;

18
Source/Project64-core/N64System/N64Types.h
View File

@ -75,14 +75,18 @@ enum Country
UnknownCountry = 0
};
enum SPECIAL_TIMERS
enum PROFILE_TIMERS
{
Timer_None = 0, Timer_R4300 = -1, Timer_RSP_Dlist = -2,
Timer_RSP_Alist = -3, Timer_RSP_Unknown = -5, Timer_RefreshScreen = -6,
Timer_UpdateScreen = -7, Timer_UpdateFPS = -9, Timer_Idel = -10,
Timer_FuncLookup = -11, Timer_Done = -13, Timer_GetBlockInfo = -14,
Timer_AnalyseBlock = -15, Timer_CompileBlock = -17, Timer_CompileDone = -18,
Timer_InheritParentInfo = -19, Timer_AddX86Code = -20,
Timer_None = 0,
Timer_R4300 = 1,
Timer_RSP_Dlist = 2,
Timer_RSP_Alist = 3,
Timer_RSP_Unknown = 4,
Timer_RefreshScreen = 5,
Timer_UpdateScreen = 6,
Timer_UpdateFPS = 7,
Timer_Idel = 8,
Timer_Max = 9,
};
enum STEP_TYPE

214
Source/Project64-core/N64System/ProfilingClass.cpp
View File

@ -17,197 +17,61 @@
enum { MAX_FRAMES = 13 };
CProfiling::CProfiling() :
m_CurrentTimerAddr(Timer_None),
m_CurrentDisplayCount(MAX_FRAMES),
m_StartTimeHi(0),
m_StartTimeLo(0)
m_CurrentTimerType(Timer_None)
{
memset(m_Timers, 0, sizeof(m_Timers));
}
SPECIAL_TIMERS CProfiling::StartTimer(SPECIAL_TIMERS Address)
void CProfiling::RecordTime(PROFILE_TIMERS timer, uint32_t TimeTaken)
{
SPECIAL_TIMERS OldTimerAddr = StopTimer();
m_CurrentTimerAddr = Address;
#ifdef _M_IX86
uint32_t HiValue, LoValue;
_asm
{
pushad;
rdtsc;
mov HiValue, edx;
mov LoValue, eax;
popad;
}
m_StartTimeHi = HiValue;
m_StartTimeLo = LoValue;
#elif !defined(_WIN32)
struct timespec now;
clock_gettime(CLOCK_MONOTONIC, &now);
m_StartTimeLo = (now.tv_sec * 1000) + (now.tv_nsec / 1000000);
#else
g_Notify->BreakPoint(__FILE__, __LINE__);
#endif
return OldTimerAddr;
m_Timers[timer] += TimeTaken;
}
SPECIAL_TIMERS CProfiling::StopTimer()
PROFILE_TIMERS CProfiling::StartTimer(PROFILE_TIMERS TimerType)
{
uint32_t HiValue, LoValue;
PROFILE_TIMERS PreviousType = StopTimer();
m_CurrentTimerType = TimerType;
m_StartTime.SetToNow();
return PreviousType;
}
if (m_CurrentTimerAddr == Timer_None) { return m_CurrentTimerAddr; }
PROFILE_TIMERS CProfiling::StopTimer()
{
if (m_CurrentTimerType == Timer_None) { return m_CurrentTimerType; }
HighResTimeStamp EndTime;
EndTime.SetToNow();
uint64_t TimeTaken = EndTime.GetMicroSeconds() - m_StartTime.GetMicroSeconds();
m_Timers[m_CurrentTimerType] += TimeTaken;
#ifdef _M_IX86
_asm {
pushad;
rdtsc;
mov HiValue, edx;
mov LoValue, eax;
popad;
}
#elif !defined(_WIN32)
struct timespec now;
clock_gettime(CLOCK_MONOTONIC, &now);
LoValue = (now.tv_sec * 1000) + (now.tv_nsec / 1000000);
#else
g_Notify->BreakPoint(__FILE__, __LINE__);
#endif
int64_t StopTime = ((uint64_t)HiValue << 32) + (uint64_t)LoValue;
int64_t StartTime = ((uint64_t)m_StartTimeHi << 32) + (uint64_t)m_StartTimeLo;
int64_t 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));
}
SPECIAL_TIMERS OldTimerAddr = m_CurrentTimerAddr;
m_CurrentTimerAddr = Timer_None;
return OldTimerAddr;
PROFILE_TIMERS CurrentTimerType = m_CurrentTimerType;
m_CurrentTimerType = Timer_None;
return CurrentTimerType;
}
void CProfiling::ShowCPU_Usage()
{
int64_t TotalTime, CPU = 0, Alist = 0, Dlist = 0, Idle = 0;
PROFILE_ENRTY Entry;
uint64_t TotalTime = m_Timers[Timer_R4300] + m_Timers[Timer_RSP_Dlist] + m_Timers[Timer_RSP_Alist] + m_Timers[Timer_Idel];
if (m_CurrentDisplayCount > 0) { m_CurrentDisplayCount -= 1; return; }
m_CurrentDisplayCount = MAX_FRAMES;
Entry = m_Entries.find(Timer_R4300);
if (Entry != m_Entries.end()) { CPU = Entry->second; }
Entry = m_Entries.find(Timer_RefreshScreen);
if (Entry != m_Entries.end()) { CPU += Entry->second; }
Entry = m_Entries.find(Timer_RSP_Dlist);
if (Entry != m_Entries.end()) { Dlist = Entry->second; }
Entry = m_Entries.find(Timer_UpdateScreen);
if (Entry != m_Entries.end()) { Dlist += Entry->second; }
Entry = m_Entries.find(Timer_RSP_Alist);
if (Entry != m_Entries.end()) { Alist = Entry->second; }
Entry = m_Entries.find(Timer_Idel);
if (Entry != m_Entries.end()) { Idle = Entry->second; }
TotalTime = CPU + Alist + Dlist + Idle;
g_Notify->DisplayMessage(0, stdstr_f("r4300i: %0.1f%c GFX: %0.1f%c Alist: %0.1f%c Idle: %0.1f%c",
(float)(((double)CPU / (double)TotalTime) * 100), '%',
(float)(((double)Dlist / (double)TotalTime) * 100), '%',
(float)(((double)Alist / (double)TotalTime) * 100), '%',
(float)(((double)Idle / (double)TotalTime) * 100), '%').c_str());
ResetCounters();
}
void CProfiling::ResetCounters()
{
m_Entries.clear();
}
struct TIMER_NAME
{
SPECIAL_TIMERS Timer;
const char * Name;
};
void CProfiling::GenerateLog()
{
stdstr LogFileName;
if (m_CurrentDisplayCount > 0)
{
CLog Log;
Log.Open("Profiling.txt");
LogFileName = Log.FileName();
//Get the total time
int64_t 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<PROFILE_VALUE *> 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
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_R4300, "R4300" },
{ Timer_RSP_Dlist, "RSP: Dlist" },
{ Timer_RSP_Alist, "RSP: Alist" },
{ Timer_RSP_Unknown, "RSP: Unknown" },
{ Timer_RefreshScreen, "Refresh Screen" },
{ Timer_UpdateScreen, "Update Screen" },
{ Timer_UpdateFPS, "Update FPS" },
{ Timer_FuncLookup, "Function Lookup" },
{ Timer_Done, "Timer_Done" },
{ Timer_GetBlockInfo, "Timer_GetBlockInfo" },
{ Timer_AnalyseBlock, "Timer_AnalyseBlock" },
{ Timer_CompileBlock, "Timer_CompileBlock" },
{ Timer_CompileDone, "Timer_CompileDone" },
};
for (size_t count = 0; count < ItemList.size(); count++)
{
char Buffer[255];
double CpuUsage = ((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 == TimerNames[NameID].Timer)
{
strcpy(Buffer, TimerNames[NameID].Name);
break;
}
}
Log.LogF("%s\t%2.2f", Buffer, CpuUsage);
}
m_CurrentDisplayCount -= 1;
return;
}
ResetCounters();
uint32_t R4300 = (uint32_t)(m_Timers[Timer_R4300] * 10000 / TotalTime);
uint32_t RSP_Dlist = (uint32_t)(m_Timers[Timer_RSP_Dlist] * 10000 / TotalTime);
uint32_t RSP_Alist = (uint32_t)(m_Timers[Timer_RSP_Alist] * 10000 / TotalTime);
uint32_t Idel = (uint32_t)(m_Timers[Timer_Idel] * 10000 / TotalTime);
m_CurrentDisplayCount = MAX_FRAMES;
g_Notify->DisplayMessage(0, stdstr_f("r4300i: %d.%02d%% GFX: %d.%02d%% Alist: %d.%02d%% Idle: %d.%02d%%",
R4300 / 100, R4300 % 100,RSP_Dlist / 100, RSP_Dlist % 100,RSP_Alist / 100, RSP_Alist % 100,Idel / 100, Idel % 100).c_str());
ResetTimers();
}
void CProfiling::ResetTimers()
{
memset(m_Timers, 0, sizeof(m_Timers));
}

24
Source/Project64-core/N64System/ProfilingClass.h
View File

@ -10,35 +10,31 @@
****************************************************************************/
#pragma once
#include <Project64-core/N64System/N64Types.h>
typedef std::map<SPECIAL_TIMERS, int64_t > PROFILE_ENRTIES;
typedef PROFILE_ENRTIES::iterator PROFILE_ENRTY;
typedef PROFILE_ENRTIES::value_type PROFILE_VALUE;
#include <Common/HighResTimeStamp.h>
class CProfiling
{
public:
CProfiling();
void RecordTime(PROFILE_TIMERS timer, uint32_t time);
uint64_t TimerTime(PROFILE_TIMERS timer);
//recording timing against current timer, returns the address of the timer stopped
SPECIAL_TIMERS StartTimer(SPECIAL_TIMERS Address);
SPECIAL_TIMERS StopTimer();
PROFILE_TIMERS StartTimer(PROFILE_TIMERS TimerType);
PROFILE_TIMERS StopTimer();
//Display the CPU Usage
void ShowCPU_Usage();
//Reset all the counters back to 0
void ResetCounters();
//Generate a log file with the current results, this will also reset the counters
void GenerateLog();
void ResetTimers(void);
private:
CProfiling(const CProfiling&); // Disable copy constructor
CProfiling& operator=(const CProfiling&); // Disable assignment
SPECIAL_TIMERS m_CurrentTimerAddr;
uint32_t m_CurrentDisplayCount;
uint32_t m_StartTimeHi, m_StartTimeLo; //The Current Timer start time
PROFILE_ENRTIES m_Entries;
PROFILE_TIMERS m_CurrentTimerType;
HighResTimeStamp m_StartTime;
uint64_t m_Timers[Timer_Max];
};

1
Source/Project64-core/N64System/Recompiler/FunctionMapClass.h
View File

@ -10,7 +10,6 @@
****************************************************************************/
#pragma once
#include <Project64-core/N64System/Recompiler/FunctionInfo.h>
#include <Project64-core/Settings/GameSettings.h>
class CFunctionMap :
private CGameSettings

53
Source/Project64-core/N64System/Recompiler/RecompilerClass.cpp
View File

@ -16,11 +16,10 @@
#include <Project64-core/N64System/Interpreter/InterpreterCPU.h>
#include <Project64-core/ExceptionHandler.h>
CRecompiler::CRecompiler(CRegisters & Registers, CProfiling & Profile, bool & EndEmulation) :
m_Registers(Registers),
m_Profile(Profile),
m_EndEmulation(EndEmulation),
PROGRAM_COUNTER(Registers.m_PROGRAM_COUNTER)
CRecompiler::CRecompiler(CRegisters & Registers, bool & EndEmulation) :
m_Registers(Registers),
m_EndEmulation(EndEmulation),
PROGRAM_COUNTER(Registers.m_PROGRAM_COUNTER)
{
CFunctionMap::AllocateMemory();
if (g_MMU != NULL)
@ -695,7 +694,29 @@ void CRecompiler::RecompilerMain_Lookup_validate_TLB()
continue;
}
}
(info->Function())();
if (bRecordExecutionTimes())
{
HighResTimeStamp StartTime, EndTime;
StartTime.SetToNow();
(info->Function())();
EndTime.SetToNow();
uint64_t TimeTaken = EndTime.GetMicroSeconds() - StartTime.GetMicroSeconds();
FUNCTION_PROFILE::iterator itr = m_BlockProfile.find(info->Function());
if (itr == m_BlockProfile.end())
{
FUNCTION_PROFILE_DATA data = { 0 };
data.Address = info->EnterPC();
std::pair<FUNCTION_PROFILE::iterator, bool> res = m_BlockProfile.insert(FUNCTION_PROFILE::value_type(info->Function(), data));
itr = res.first;
}
WriteTrace(TraceN64System, TraceNotice, "EndTime: %X StartTime: %X TimeTaken: %X", (uint32_t)EndTime.GetMicroSeconds(), (uint32_t)StartTime.GetMicroSeconds(), (uint32_t)TimeTaken);
itr->second.TimeTaken += TimeTaken;
}
else
{
(info->Function())();
}
}
else
{
@ -1108,4 +1129,22 @@ void CRecompiler::ResetMemoryStackPos()
WriteTrace(TraceRecompiler, TraceError, "Failed to translate SP address (%s)", m_Registers.m_GPR[29].UW[0]);
g_Notify->BreakPoint(__FILE__, __LINE__);
}
}
}
void CRecompiler::DumpFunctionTimes()
{
CPath LogFileName(g_Settings->LoadStringVal(Directory_Log).c_str(), "FunctionTimes.csv");
CLog Log;
Log.Open(LogFileName);
for (FUNCTION_PROFILE::iterator itr = m_BlockProfile.begin(); itr != m_BlockProfile.end(); itr++)
{
Log.LogF("%X,0x%X,%d\r\n", (uint32_t)itr->first, itr->second.Address, (uint32_t)itr->second.TimeTaken);
}
}
void CRecompiler::ResetFunctionTimes()
{
m_BlockProfile.clear();
}

14
Source/Project64-core/N64System/Recompiler/RecompilerClass.h
View File

@ -40,7 +40,7 @@ public:
typedef void(*DelayFunc)();
public:
CRecompiler(CRegisters & Registers, CProfiling & Profile, bool & EndEmulation);
CRecompiler(CRegisters & Registers, bool & EndEmulation);
~CRecompiler();
void Run();
@ -52,6 +52,8 @@ public:
void ClearRecompCode_Phys(uint32_t PhysicalAddress, int32_t length, REMOVE_REASON Reason);
void ResetMemoryStackPos();
void ResetFunctionTimes();
void DumpFunctionTimes();
uint32_t& MemoryStackPos() { return m_MemoryStack; }
@ -62,6 +64,14 @@ private:
CCompiledFunc * CompileCode();
typedef struct
{
uint32_t Address;
uint64_t TimeTaken;
} FUNCTION_PROFILE_DATA;
typedef std::map <CCompiledFunc::Func, FUNCTION_PROFILE_DATA> FUNCTION_PROFILE;
// Main loops for the different look up methods
void RecompilerMain_VirtualTable();
void RecompilerMain_VirtualTable_validate();
@ -73,9 +83,9 @@ private:
CCompiledFuncList m_Functions;
CRegisters & m_Registers;
CProfiling & m_Profile;
bool & m_EndEmulation;
uint32_t m_MemoryStack;
FUNCTION_PROFILE m_BlockProfile;
//Quick access to registers
uint32_t & PROGRAM_COUNTER;

4
Source/Project64-core/Settings/DebugSettings.cpp
View File

@ -18,6 +18,7 @@ bool CDebugSettings::m_bLogX86Code = false;
bool CDebugSettings::m_bShowTLBMisses = false;
bool CDebugSettings::m_bShowDivByZero = false;
bool CDebugSettings::m_Registered = false;
bool CDebugSettings::m_RecordExecutionTimes = false;
CDebugSettings::CDebugSettings()
{
@ -29,6 +30,7 @@ CDebugSettings::CDebugSettings()
g_Settings->RegisterChangeCB(Debugger_GenerateLogFiles, this, (CSettings::SettingChangedFunc)StaticRefreshSettings);
g_Settings->RegisterChangeCB(Debugger_ShowTLBMisses, this, (CSettings::SettingChangedFunc)StaticRefreshSettings);
g_Settings->RegisterChangeCB(Debugger_ShowDivByZero, this, (CSettings::SettingChangedFunc)StaticRefreshSettings);
g_Settings->RegisterChangeCB(Debugger_RecordExecutionTimes, this, (CSettings::SettingChangedFunc)StaticRefreshSettings);
RefreshSettings();
}
@ -43,6 +45,7 @@ CDebugSettings::~CDebugSettings()
g_Settings->UnregisterChangeCB(Debugger_GenerateLogFiles, this, (CSettings::SettingChangedFunc)StaticRefreshSettings);
g_Settings->UnregisterChangeCB(Debugger_ShowTLBMisses, this, (CSettings::SettingChangedFunc)StaticRefreshSettings);
g_Settings->UnregisterChangeCB(Debugger_ShowDivByZero, this, (CSettings::SettingChangedFunc)StaticRefreshSettings);
g_Settings->UnregisterChangeCB(Debugger_RecordExecutionTimes, this, (CSettings::SettingChangedFunc)StaticRefreshSettings);
}
}
@ -52,4 +55,5 @@ void CDebugSettings::RefreshSettings()
m_bLogX86Code = m_bHaveDebugger && g_Settings->LoadBool(Debugger_GenerateLogFiles);
m_bShowTLBMisses = m_bHaveDebugger && g_Settings->LoadBool(Debugger_ShowTLBMisses);
m_bShowDivByZero = m_bHaveDebugger && g_Settings->LoadBool(Debugger_ShowDivByZero);
m_RecordExecutionTimes = g_Settings->LoadBool(Debugger_RecordExecutionTimes);
}

2
Source/Project64-core/Settings/DebugSettings.h
View File

@ -22,6 +22,7 @@ public:
static inline bool bLogX86Code(void) { return m_bLogX86Code; }
static inline bool bShowTLBMisses(void) { return m_bShowTLBMisses; }
static inline bool bShowDivByZero(void) { return m_bShowDivByZero; }
static inline bool bRecordExecutionTimes(void) { return m_RecordExecutionTimes; }
private:
static void StaticRefreshSettings(CDebugSettings * _this)
@ -36,6 +37,7 @@ private:
static bool m_bLogX86Code;
static bool m_bShowTLBMisses;
static bool m_bShowDivByZero;
static bool m_RecordExecutionTimes;
static int32_t m_RefCount;
static bool m_Registered;

1
Source/Project64-core/Settings/Settings.h
View File

@ -221,6 +221,7 @@ enum SettingID
Debugger_ShowDListAListCount,
Debugger_ShowRecompMemSize,
Debugger_DebugLanguage,
Debugger_RecordExecutionTimes,
//Trace
Debugger_TraceMD5,

1
Source/Project64-core/Settings/SettingsClass.cpp
View File

@ -309,6 +309,7 @@ void CSettings::AddHowToHandleSetting(const char * BaseDirectory)
AddHandler(Debugger_DisableGameFixes, new CSettingTypeApplication("Debugger", "Disable Game Fixes", false));
AddHandler(Debugger_ShowDListAListCount, new CSettingTypeApplication("Debugger", "Show Dlist Alist Count", false));
AddHandler(Debugger_ShowRecompMemSize, new CSettingTypeApplication("Debugger", "Show Recompiler Memory size", false));
AddHandler(Debugger_RecordExecutionTimes, new CSettingTypeApplication("Debugger", "Record Execution Times", false));
AddHandler(Debugger_DebugLanguage, new CSettingTypeApplication("Debugger", "Debug Language", false));
AddHandler(Debugger_ShowDivByZero, new CSettingTypeApplication("Debugger", "Show Div by zero", false));
AddHandler(Debugger_ProfileCode, new CSettingTypeApplication("Debugger", "Profile Code", (uint32_t)false));

12
Source/Project64/Project64.vcxproj.filters
View File

@ -162,6 +162,12 @@
<ClCompile Include="Settings\UISettings.cpp">
<Filter>Source Files\Settings Files</Filter>
</ClCompile>
<ClCompile Include="UserInterface\SupportWindow.cpp">
<Filter>Source Files\User Interface Source</Filter>
</ClCompile>
<ClCompile Include="UserInterface\SupportEnterCode.cpp">
<Filter>Source Files\User Interface Source</Filter>
</ClCompile>
</ItemGroup>
<ItemGroup>
<ClInclude Include="UserInterface\resource.h">
@ -293,6 +299,12 @@
<ClInclude Include="Settings\UISettings.h">
<Filter>Header Files\Settings</Filter>
</ClInclude>
<ClInclude Include="UserInterface\SupportWindow.h">
<Filter>Header Files\User Interface Headers</Filter>
</ClInclude>
<ClInclude Include="UserInterface\SupportEnterCode.h">
<Filter>Header Files\User Interface Headers</Filter>
</ClInclude>
</ItemGroup>
<ItemGroup>
<None Include="res\divider.cur">

2
Source/Project64/UserInterface/MainMenuClass.cpp
View File

@ -483,7 +483,7 @@ bool CMainMenu::ProcessMessage(HWND hWnd, DWORD /*FromAccelerator*/, DWORD MenuI
g_BaseSystem->ExternalEvent(SysEvent_Profile_StartStop);
break;
case ID_PROFILE_RESETCOUNTER: g_BaseSystem->ExternalEvent(SysEvent_Profile_ResetLogs); break;
case ID_PROFILE_GENERATELOG: g_BaseSystem->ExternalEvent(SysEvent_Profile_GenerateLogs); break;
case ID_PROFILE_GENERATELOG: g_BaseSystem->ExternalEvent(SysEvent_DumpFunctionTimes); break;
case ID_DEBUG_SHOW_TLB_MISSES:
g_Settings->SaveBool(Debugger_ShowTLBMisses, !g_Settings->LoadBool(Debugger_ShowTLBMisses));
break;