Apple-2-Tools/AppleWin
1
0
Fork 0
mirror of https://github.com/AppleWin/AppleWin.git synced 2025-01-16 09:30:00 +00:00
Code Issues Projects Releases Wiki Activity

Added a new PerfMarker class: used to instrument emulation sub-systems and log timings (#788)

Browse Source 
To enable this uncomment the #define LOG_PERF_TIMINGS in AppleWin.h.
This commit is contained in:
tomcw 2020-05-23 16:23:06 +01:00
parent b1ab3f9794
commit 13a4043118
6 changed files with 102 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

51
source/Applewin.cpp
View File

@ -123,11 +123,51 @@ CSpeech g_Speech;
//===========================================================================
#ifdef LOG_PERF_TIMINGS
static UINT64 g_timeTotal = 0;
UINT64 g_timeCpu = 0;
UINT64 g_timeVideo = 0; // part of timeCpu
UINT64 g_timeMB_Timer = 0; // part of timeCpu
UINT64 g_timeMB_NoTimer = 0;
UINT64 g_timeSpeaker = 0;
static UINT64 g_timeVideoRefresh = 0;
void LogPerfTimings(void)
{
if (g_timeTotal)
{
UINT64 cpu = g_timeCpu - g_timeVideo - g_timeMB_Timer;
UINT64 video = g_timeVideo + g_timeVideoRefresh;
UINT64 spkr = g_timeSpeaker;
UINT64 mb = g_timeMB_Timer + g_timeMB_NoTimer;
UINT64 audio = spkr + mb;
UINT64 other = g_timeTotal - g_timeCpu - g_timeSpeaker - g_timeMB_NoTimer - g_timeVideoRefresh;
LogOutput("Perf breakdown:\n");
LogOutput(". CPU %% = %2f.2\n", (double)cpu / (double)g_timeTotal * 100.0);
LogOutput(". Video %% = %2f.2\n", (double)video / (double)g_timeTotal * 100.0);
LogOutput("... NTSC %% = %2f.2\n", (double)g_timeVideo / (double)g_timeTotal * 100.0);
LogOutput("... refresh %% = %2f.2\n", (double)g_timeVideoRefresh / (double)g_timeTotal * 100.0);
LogOutput(". Audio %% = %2f.2\n", (double)audio / (double)g_timeTotal * 100.0);
LogOutput("... Speaker %% = %2f.2\n", (double)spkr / (double)g_timeTotal * 100.0);
LogOutput("... MB %% = %2f.2\n", (double)mb / (double)g_timeTotal * 100.0);
LogOutput(". Other %% = %2f.2\n", (double)other / (double)g_timeTotal * 100.0);
LogOutput(". TOTAL %% = %2f.2\n", (double)(cpu+video+audio+other) / (double)g_timeTotal * 100.0);
}
}
#endif
//===========================================================================
static DWORD dwLogKeyReadTickStart;
static bool bLogKeyReadDone = false;
void LogFileTimeUntilFirstKeyReadReset(void)
{
#ifdef LOG_PERF_TIMINGS
LogPerfTimings();
#endif
if (!g_fh)
return;
@ -234,6 +274,10 @@ static bool g_uModeStepping_LastGetKey_ScrollLock = false;
static void ContinueExecution(void)
{
#ifdef LOG_PERF_TIMINGS
PerfMarker* pPerfMarkerTotal = new PerfMarker(g_timeTotal);
#endif
_ASSERT(g_nAppMode == MODE_RUNNING || g_nAppMode == MODE_STEPPING);
const double fUsecPerSec = 1.e6;
@ -352,6 +396,9 @@ static void ContinueExecution(void)
const UINT dwClksPerFrame = NTSC_GetCyclesPerFrame();
if (g_dwCyclesThisFrame >= dwClksPerFrame && !VideoGetVblBarEx(g_dwCyclesThisFrame))
{
#ifdef LOG_PERF_TIMINGS
PerfMarker perfMarkerVideoRefresh(g_timeVideoRefresh);
#endif
g_dwCyclesThisFrame -= dwClksPerFrame;
if (g_bFullSpeed)
@ -360,6 +407,10 @@ static void ContinueExecution(void)
VideoRefreshScreen(); // Just copy the output of our Apple framebuffer to the system Back Buffer
}
#ifdef LOG_PERF_TIMINGS
delete pPerfMarkerTotal; // Explicitly call dtor *before* SysClk_WaitTimer()
#endif
if ((g_nAppMode == MODE_RUNNING && !g_bFullSpeed) || bModeStepping_WaitTimer)
{
SysClk_WaitTimer();

24
source/Applewin.h
View File

@ -63,3 +63,27 @@ extern CSpeech g_Speech;
#endif
extern __interface IPropertySheet& sg_PropertySheet;
//
//#define LOG_PERF_TIMINGS
#ifdef LOG_PERF_TIMINGS
class PerfMarker
{
public:
PerfMarker(UINT64& globalCounter)
: counter(globalCounter)
{
QueryPerformanceCounter(&timeStart);
}
~PerfMarker()
{
QueryPerformanceCounter(&timeEnd);
counter += (UINT64)timeEnd.QuadPart - (UINT64)timeStart.QuadPart;
}
private:
UINT64& counter;
LARGE_INTEGER timeStart;
LARGE_INTEGER timeEnd;
};
#endif

5
source/CPU.cpp
View File

@ -564,6 +564,11 @@ ULONG CpuGetCyclesThisVideoFrame(const ULONG nExecutedCycles)
DWORD CpuExecute(const DWORD uCycles, const bool bVideoUpdate)
{
#ifdef LOG_PERF_TIMINGS
extern UINT64 g_timeCpu;
PerfMarker perfMarker(g_timeCpu);
#endif
g_nCyclesExecuted = 0;
#ifdef _DEBUG

13
source/Mockingboard.cpp
View File

@ -814,7 +814,7 @@ static UINT64 g_uLastMBUpdateCycle = 0;
// Called by:
// . MB_UpdateCycles() - when g_nMBTimerDevice == {0,1,2,3}
// . MB_PeriodicUpdate() - when g_nMBTimerDevice == kTIMERDEVICE_INVALID
static void MB_Update(void)
static void MB_UpdateInt(void)
{
if (!MockingboardVoice.bActive)
return;
@ -1021,6 +1021,17 @@ static void MB_Update(void)
#endif
}
static void MB_Update(void)
{
#ifdef LOG_PERF_TIMINGS
extern UINT64 g_timeMB_NoTimer;
extern UINT64 g_timeMB_Timer;
PerfMarker perfMarker(g_nMBTimerDevice == kTIMERDEVICE_INVALID ? g_timeMB_NoTimer : g_timeMB_Timer);
#endif
MB_UpdateInt();
}
//-----------------------------------------------------------------------------
// Called by SSI263Thread(), MB_LoadSnapshot & Phasor_LoadSnapshot

5
source/NTSC.cpp
View File

@ -2091,6 +2091,11 @@ static void VideoUpdateCycles( int cyclesLeftToUpdate )
//===========================================================================
void NTSC_VideoUpdateCycles( UINT cycles6502 )
{
#ifdef LOG_PERF_TIMINGS
extern UINT64 g_timeVideo;
PerfMarker perfMarker(g_timeVideo);
#endif
_ASSERT(cycles6502 && cycles6502 < g_videoScanner6502Cycles); // Use NTSC_VideoRedrawWholeScreen() instead
if (g_bDelayVideoMode)

5
source/Speaker.cpp
View File

@ -415,6 +415,11 @@ BYTE __stdcall SpkrToggle (WORD, WORD, BYTE, BYTE, ULONG nExecutedCycles)
// Called by ContinueExecution()
void SpkrUpdate (DWORD totalcycles)
{
#ifdef LOG_PERF_TIMINGS
extern UINT64 g_timeSpeaker;
PerfMarker perfMarker(g_timeSpeaker);
#endif
if(!g_bSpkrToggleFlag)
{
if(!g_nSpkrQuietCycleCount)